MessageService DrainLoop throws OutOfMemoryException during hub delivery (recurrence of #4824)

What is failing

The MeshWeaver.Messaging MessageService delivery pipeline (MessageService.DrainLoop()) threw System.OutOfMemoryException while subscribing deliveries for hub thomas.pepin/_Install/GraphViews on a memex-cloud portal pod. As in the earlier burst, the stack runs through a long chain of nested System.Reactive ObservableImpl.SelectMany / ReturnImmediate frames, pointing at unbounded accumulation of in-flight work (or an already-exhausted heap) rather than one oversized allocation.

Probable cause

This is a recurrence of #4824 (incident Admin/_LogIncident/32768bfc4b1eeb3f, 2026-09-19, 4 occurrences across two pods, same category/message/top frame). The same analysis applies with unchanged, medium confidence: either (a) a re-subscription/repost loop in the drain loop's reactive chain growing the set of pending inner subscriptions until the heap is exhausted, or (b) a memory leak elsewhere pinning hub graphs so that the delivery pipeline is merely the first allocation to fail. The recurring pattern across unrelated hub paths on different days slightly favours the leak hypothesis. No new stack shape is present — the truncated stack again shows no MessageService frame above the Rx machinery.

Impact

Single occurrence so far today, on one pod (memex-portal-deployment-777677694-cc6zz); the affected hub's delivery was lost, not retried. Taken together with #4824, this is now the second burst in four days in namespace memex-cloud — an intermittent user-visible delivery failure that indicates the underlying leak/storm has not been fixed and is degrading pods until restart.

Where to look

MeshWeaver.Messaging.MessageService.DrainLoop() — the log site and top application frame; the same starting point as RoutingGrain route dispatch fails with OutOfMemoryException during pod-wide heap exhaustion — downstream of ObjectPolymorphicConverter OOM burst #4824.
Follow the playbook in Debugging Disposal and Leaks: trace distinct messages per hub with MESHWEAVER_MSG_TRACE=1 to rule a repost storm in or out, and run the ClrMD GC-root probe (test/MeshWeaver.Hosting.Monolith.Test/MeshHubDisposalLeakTest.cs) on the pod to identify the pinning root.
Compare pod memory telemetry at 2026-09-23 14:22 UTC against the 2026-09-19 06:30 UTC burst from RoutingGrain route dispatch fails with OutOfMemoryException during pod-wide heap exhaustion — downstream of ObjectPolymorphicConverter OOM burst #4824 — a repeated steady climb points squarely at the leak.
Likely duplicate of RoutingGrain route dispatch fails with OutOfMemoryException during pod-wide heap exhaustion — downstream of ObjectPolymorphicConverter OOM burst #4824; consider merging this recurrence into that investigation if the triage findings match.

Evidence


Fingerprint	`d54c022857121762`
Category	`MeshWeaver.Messaging.MessageService`
Severity	Error
Exception	`System.OutOfMemoryException`
Top frame	`MeshWeaver.Messaging.MessageService.DrainLoop()`
Namespace	`memex-cloud`
Pods	`memex-portal-deployment-777677694-cc6zz`
Occurrences	1
First seen	2026-09-23 14:22:38Z
Last seen	2026-09-23 14:22:38Z
Routing	not determined — no configured route matches the category `MeshWeaver.Messaging.MessageService`. This repository is the configured fallback, not a finding about who owns the fault; the category names the LOGGER, which may not be the subject.

Recent log lines

2026-09-23 14:22:38Z memex-portal-deployment-777677694-cc6zz fail: MeshWeaver.Messaging.MessageService[0]
      Unhandled exception in delivery pipeline for hub thomas.pepin/_Install/GraphViews
      System.OutOfMemoryException: Exception of type 'System.OutOfMemoryException' was thrown.
         at System.Reactive.Linq.ObservableImpl.SelectMany`2.ObservableSelector.CreateSink(IObserver`1 observer)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserv…[truncated]

_{Opened automatically from Admin/_LogIncident/d54c022857121762. Recurrences are folded into this issue rather than opening new ones.}

Still occurring: 0 more since the last update (1 total).

Last seen: 2026-09-23 14:22:38Z
Pods: memex-portal-deployment-777677694-cc6zz

Recent log lines

2026-09-23 14:22:38Z memex-portal-deployment-777677694-cc6zz fail: MeshWeaver.Messaging.MessageService[0]
      Unhandled exception in delivery pipeline for hub thomas.pepin/_Install/GraphViews
      System.OutOfMemoryException: Exception of type 'System.OutOfMemoryException' was thrown.
         at System.Reactive.Linq.ObservableImpl.SelectMany`2.ObservableSelector.CreateSink(IObserver`1 observer)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
         at System.Reactive.Sink`2.Run(IObservable`1 source)
         at System.Reactive.Producer`2.SubscribeRaw(IObserv…[truncated]

A 9.7 GiB burst in 107 seconds, on a process about 6 minutes old. This was not the slow leak.

Session 2026-09-23 ~16:40–18:15Z. Read-only apart from Logs InstanceActions on the control instance (Ops/Actions/logs-memex-cloud-20260923-oom-cc6zz*). No code change. Stays open.

1. The process that threw was on a current image and had just started

Ops/Status/memex-cloud v2680 (sampled 14:26:01Z) reads pod memex-portal-deployment-777677694-cc6zz: image 3.0.0-ci.9258, commit 9a61fed9 (current main, which carries #4972, #5206 and #5311), startedAt 14:11:52Z, restarts: 1, and the replacement process booted at 14:24:10Z.

2. Its own `[LIVENESS]` line shows the heap curve (`heap=` is `GC.GetTotalMemory(false)`, logged every 10 s)

time (Z)	tick	heap	gcPause (cumulative)	poolPending
14:17:50	30	2.01 GiB	2.41 s	0
14:19:37	40 (10 ticks took 107 s)	11.70 GiB	26.25 s	0
14:21:31	50	11.66 GiB	129.06 s	715

Then 7 OutOfMemoryException lines on that pod, between 14:21:21Z and 14:22:40Z (…-oomonly: 9 lines matched, not cut, all landed; the other 2 are createdump lines). The 14:22:38Z one is this issue's. At 14:22:42Z two [createdump] … Unwind: exception type System.OutOfMemoryException lines mark the process dying on an unhandled OOM, which accounts for restarts: 1.

So the heap grew ~9.7 GiB in 107 s (~90 MB/s), from about 6 minutes after boot. #3432 measured ~210 MB/h. At that rate this growth would take about two days, so the slow-retention reading ("a memory leak elsewhere pinning hub graphs") does not explain this occurrence. Something allocated and held (the heap stayed at 11.66 GiB through 129 s of cumulative GC pause) a very large amount of memory in under two minutes during startup.

3. The stack shape carries no signal

The nested SelectMany/Producer.SubscribeRaw/Sink.Run frames are the normal shape of every delivery on a per-node hub, not a growing chain. MessageHub.HandleMessageAsync (src/MeshWeaver.Messaging.Hub/MessageHub.cs:1090-1095) folds the hub's rule list with one SelectMany per rule, and every configured handler type is its own rule (:639-647). The chain is rebuilt per message from a snapshot, and its length is bounded (the rules are registered at build time; every runtime Register in src/ is disposed with its stream). DrainLoop only logs the fault (MessageService.cs:1758-1767). An OOM here means the allocation that failed was the first one attempted after the heap ran out. thomas.pepin/_Install/GraphViews is the hub it happened to land on.

4. Leads, NOT established

What allocated the 9.7 GiB. Candidates, in no order: the startup NodeType bake (the three peers booted the same minute logged compiling sweep at 14:18:50–14:21:06Z, the same window), and a per-viewer install/app-tile sweep (both DrainLoop OOM bursts, 09-19 and today, include _Install/<package> hubs among their victims: thomas.mager/_Install/SocialMedia and thomas.pepin/_Install/GraphViews; on 09-17 one replica recorded ×3,097 degraded Store/Install reads). These are co-occurrences, not causes.
Whether the peers spiked too. I filed Ops/Actions/logs-memex-cloud-20260923-heap-peers (pod …-d4j8c, ticks 20–60, 27 lines read). It was still landing when my control-instance session ended, so I read nothing from it. If d4j8c shows the same ~10 GiB step and survived, the burst is ordinary startup work on every replica and the difference is headroom. If it stayed flat, cc6zz was given something the others were not.
The second process on cc6zz still climbed: 1.22 GiB at 14:36:34Z (tick 69) to 3.16 GiB at 15:50:09Z (tick 510), with gen2 128→410 and gcPause 3.99→37.88 s. That is ~1.6 GiB/h. It matters for 6,925 Started sync/ hubs hold ~2.7 GB of a 3.5 GB live heap — population MEASURED, cause NOT established (split from #3321) #3432 (cross-posted there), but GetTotalMemory(false) includes uncollected garbage, so it is an upper bound and not a retained-heap measurement.

Next reading (cheap, read-only, no dump)

Logs with pod and query: "LIVENESS\\] tick=(2[0-9]|3[0-9]|4[0-9]) gap" on the peers, plus the same pod's non-LIVENESS lines between 14:17:50Z and 14:19:37Z. That second read needs either an end-time bound on the Logs action (it only has sinceMinutes, so the newest 200 lines of a long-lived pod always crowd out an early window) or a pattern specific enough to reach back.

Incidental, filed into triage (rbuergi/Feedback/20260923-1655-logs-action-created-armed-lands-nothing): a Logs action created with requestedAction already set read its window and then landed 0/124 lines (AccessContext must never be null). Re-arming it with a patch landed them.

_{Claude Opus 5.5 — read-only; the only writes were Logs InstanceActions and one triage Feedback node on memex.systemorph.com.}

Consolidated bot-filed duplicates of this defect (closed not_planned): #5552 #5553 #5554 — the same OutOfMemoryException event on pod memex-portal-deployment-777677694-cc6zz, 14:22:25-14:22:38Z — the dispose/drain sites are where the one heap exhaustion surfaced. The filer fan-out that minted them (no lookup of an existing issue for the same log site) is fixed in Systemorph/MeshWeaver.Plugins#2290.

The multi-GiB step is not a single-pod startup event. It recurs, lands on several replicas in the same minute, and lines up with replicas leaving or joining

Session 2026-09-24 06:40–07:30Z on memex.meshweaver.cloud (/api/version = 9a61fed964, 3.0.0-ci.9263, until the 07:00Z roll to bf5ac85526 / 3.0.0-ci.9287). The only writes were Logs InstanceActions under Ops/logs-memexcloud-20260924-* on memex-cloud. No code changed.

1. The instrument and the denominator

Every 10th [LIVENESS] line (tick ending in 0, so one every 100 s), per pod, over 760 min: Ops/logs-memexcloud-20260924-liveness-{9p7z4,5hflx,5x2kg,2x9rq}. 1,163 lines, 4 pods, about 32 pod-hours, one process per pod. heap= is GC.GetTotalMemory(false).

2. The step recurs on the same image, far from boot

Every jump of ≥ 1.5 GiB within one 100 s sample:

pod	time (Z)	heap	gcPause in that 100 s
9p7z4	09-23 18:54:47 (boot + 6 min)	0.37 → 8.52 → 10.49 (next sample)	+10.0 s, +13.5 s; poolPending 688
5hflx	09-23 19:09:49	0.79 → 5.87	+7.2 s
5hflx	09-23 21:13–21:14	1.87 → 4.07 → 5.57	+3.5 s, +4.7 s
9p7z4	09-23 21:26:45	1.86 → 3.89	+2.8 s
9p7z4	09-24 01:00:11	2.44 → 5.65	+4.1 s
5hflx	09-24 01:00:02	2.80 → 5.67	+4.7 s
9p7z4	09-24 03:31:56	2.57 → 5.03	+3.5 s
5x2kg	09-24 03:31:48	0.94 → 2.79	+4.4 s

The 01:00Z pair is nine seconds apart on two different nodes, and replica …-5x2kg booted at 01:00:28Z. The 03:31Z pair is eight seconds apart. A step that reaches two processes on two nodes in the same few seconds is not something one process does to itself at boot. It is something the cluster hands to the replicas that remain.

On 9p7z4 the 18:54Z step stayed live: the heap held 10.5–10.8 GiB from 18:56 to 19:05 across gen2 collections (gen2 51 → 56), then came down in steps over about an hour (8.8, 7.4, 6.0, 4.6, 2.2 GiB at 19:52Z). cc6zz on 09-23 took the same kind of step (2.0 → 11.7 GiB) and died of it. 9p7z4 stopped about 1 GiB short.

It is not every boot. In the same 760 min, replicas …-5x2kg (01:00Z), …-2x9rq (03:42Z) and …-v4txp (06:43Z) booted and stayed at 0.4–1.9 GiB through their first hour. Five replicas of the 07:00Z roll read 0.44–1.68 GiB at 6–12 min uptime.

3. Replicas are dying from other causes, and each death is a candidate trigger

Ops/logs-memexcloud-20260924-createdump (Unwind: exception type, every pod, 1000 min) returned 4 lines:

time (Z)	pod	exception
09-23 17:57:11	`…4d84f9-wl8mv`	`MeshWeaver.Mesh.QueryProviderStalledException`, unhandled
09-23 18:10:38	`…4d84f9-n7g6b`	`MeshWeaver.Mesh.QueryProviderStalledException`, unhandled
09-24 06:49:48	`…76cf776847-5hflx`	`System.StackOverflowException`
09-24 06:56:01	`…76cf776847-v4txp`	`System.StackOverflowException`

A QueryProviderStalledException terminates the process. Since feat: the query fan-in's Initial stall is a TERMINAL, not a warning #5048 the stall is a terminal OnError, and something subscribes to it with no error arm, so Rx rethrows on a thread. I found no issue for this.
The StackOverflow's bottom frames (Ops/logs-memexcloud-20260924-stackoverflow-v4txp) are ThreadPool → MessageService.DrainOne → DrainLoop → CurrentThreadScheduler.Schedule → about 20 nested Producer.SubscribeRaw/Sink.Run pairs over Using/Finally/Catch/Defer/Do/Select. Both deaths came during the 06:47Z roll, so they may be teardown recursion. I did not get the repeating block: two reads targeted at it were lost when the pod running the Logs observer was rolled away.
The two 4d84f9 deaths and the start of the 76cf776847 roll fall inside 51 minutes of each other. The 18:54Z step on 9p7z4 is in that window.
🚨 Disclosure: at 06:50Z and 06:56Z I called MCP export @Ops/Logs (a subtree of ~2,200 LogEntry nodes), and both calls dropped the transport. Those are within seconds of the two StackOverflow deaths. The deaths also fall inside a roll that was replacing those pods. An isolated Rx Merge(16) over 3,000 synchronous inners has constant stack depth (22 frames) on System.Reactive 7.0.0, which clears the obvious recursion in MeshOperations.Export. I have not excluded the export as the trigger. Until someone does, a large MCP export should be treated as a candidate replica-killer.

4. What this changes about the reading on this issue

The stack in the body (SelectMany.CreateSink under DrainLoop) is still just where the first failed allocation landed, as the 09-23 comment said.
The allocator is still not named. What is established: it is a burst of live data, 2–10 GiB, arriving on several replicas within seconds of each other, at times that coincide with a replica joining or leaving (01:00:02–01:00:28Z). The leading shape is mass re-activation of the departed silo's hubs on the survivors, each activation paying the ~390 KB per-hub scope that 6,925 Started sync/ hubs hold ~2.7 GB of a 3.5 GB live heap — population MEASURED, cause NOT established (split from #3321) #3432 measured, and the amount released stepwise about an hour later as idle activations deactivate. This is a hypothesis. The reading that would confirm it is an Orleans activation count (or the sync/ census) before and after one replica leaves.
The thomas.pepin/_Install/GraphViews victim fits the same shape. _Install/* hubs are the per-user activations a sweep touches after a roll (Portal routing legs starved of ThreadPool threads during install burst (routing saturation gauge, not a routing defect) #5389, Plugins#2329, which is on the image that still stepped on 09-23 18:54Z).

Not established

The allocator's identity. DynamicTypePreWarmer summaries are multi-line (the header line matches a query, the message line does not), so the bake-cost MemoryDelta for 18:54Z was not read.
Membership events at 21:13Z and 03:31Z. A namespace-wide read timed out at Loki's 45 s budget.
Whether the StackOverflow was the export or the roll.

_{Claude Opus 5.5. Logs InstanceActions on memex.meshweaver.cloud only. No roll, restart or recycle.}

Consolidated here (closed not_planned, 2026-09-24): #5614 and #5601, OOMs whose failing allocation is incidental to a pod-wide heap exhaustion, with no Orleans deep-copy frame.

PostgreSQL storage adapter OOMs re-serializing node JSON in EnsureTypeDiscriminatorFirst during query #5614 is ExceptionHandlerMiddleware[1] OOM in Utf8JsonWriter.Grow ← PostgreSqlStorageAdapter.EnsureTypeDiscriminatorFirst. It fired on memex-cloud 6f497dc9b-j9vq8 at 2026-09-23 18:38:29Z. That is the same pod and minute as the deep-copy OOMs Orleans routing drops delivery when JsonCodec deep-copy deserializes an unboundedly deep object graph (ReadStack OOM) #5612/Message delivery to instance fails with OutOfMemoryException in AddressConverter.Read during Orleans JSON deep copy #5613 (folded into RoutingGrain route dispatch fails with OutOfMemoryException during pod-wide heap exhaustion — downstream of ObjectPolymorphicConverter OOM burst #4824), and the same unhandled request OnboardingMiddleware writes JSON responses into a disposed Kestrel MemoryPool during portal shutdown #4859 saw.
NamedAreaView control stream dies with OutOfMemoryException during polymorphic JSON type-info configuration #5601 is NamedAreaView OOM in HashSet.Resize ← PolymorphicTypeInfoResolver.ComputeDerivedTypes. It fired on 7d7f4d84f9-n7g6b at 18:07:31Z/18:07:34Z.

Both fall inside the multi-GiB heap-step window this issue tabulates. For 6f497dc9b-j9vq8 specifically I have not established which step it was.

The allocator is still not named. #5665 adds the in-band reading that would name it. One causal arrow on this issue probably points the other way.

Session 2026-09-24 ~13:50–14:35Z. The only production writes were two Logs InstanceActions on memex-cloud (Ops/logs-memexcloud-20260924-heapstep-{ghgjt,vn49b}). Loki answered 429 / 45 s timeouts for most of the session, and one read landed: 198 [LIVENESS] lines from …589ff8f895-ghgjt.

1. The 01:00Z "replica joined" is more likely the step's effect than its cause (not established)

…-5x2kg, which booted at 01:00:28Z, is in the same ReplicaSet (76cf776847) as 9p7z4 and 5hflx. So this was a scale event, not a roll.
memex-cloud runs KEDA (values.ha.yaml / values.memexcloud.public.yaml: keda.enabled: true, min 2, max 8). The chart's ScaledObject (deploy/helm/templates/memex-portal/scaledobject.yaml) has a memory trigger at 80 % of the 8 GiB request and a 30 s scale-up stabilisation window.
The two pods stepped to about 5.6 GiB of managed heap at 01:00:02Z and 01:00:11Z, and RSS runs higher than that. A new pod started 26 s later. That is the timing a memory scale-up would produce.
So for 01:00Z the likely order is step, then scale-up, not a join followed by a step. The later "replicas leaving" match the chart's slow scale-down (600 s stabilisation, one pod per 300 s).
The "mass re-activation of a departed silo's hubs" hypothesis needs a departure before the step, and Ops/logs-memexcloud-20260924-membership-9p7z4 shows no membership line on 9p7z4 around 01:00Z or 03:31Z. Only its boot-time connectivity check appears, at 18:49:52Z.
Not established: HPA/KEDA events are not in Loki, so the scale decision itself was not read.

2. What else I ruled out while reading the code

Per-membership-change fan-out. OrleansRoutingService.AttachPodHub / ReattachOnMembershipChange re-assert per registered stream address. The callers are the per-pod singletons (portal/nodeops, reads, the stream hub, cache, session, portal circuits), not the sync/ hubs. That is tens of grain calls per change, not gigabytes.
The StackOverflow under DrainOne → DrainLoop is StackOverflowException kills the portal: Rx Merge(maxConcurrent) recurses once per queued inner when inners complete synchronously (export during a roll) #5649's Merge(n) dequeue recursion, fixed in fix(rx): bounded fan-outs dequeue through the trampoline — MergeBounded replaces bare Merge(n) (StackOverflow, #5649) #5651 (merged, awaiting roll). I found no second recursion in DrainLoop.

3. Why no fix, and what #5665 does instead

The evidence I could reach does not name the allocation, so I am not shipping a speculative fix. The reading that would name it is what was allocated inside the tick where the heap stepped. A Heap dump cannot take that reading: it restarts a replica this size (PortalHeapIsHubs), and the step cannot be predicted.

#5665 adds AllocationByTypeSampler, an in-process listener on the runtime's own GCAllocationTick events (one per ~100 KB allocated, carrying the type). The heartbeat now logs a [HEAPSTEP] Warning on any tick whose heap grew by ≥ 512 MiB, naming the 8 heaviest types allocated in that window. It has a deterministic test with a negative control.

After it rolls, the next step names its leading type in the log. Read it with Logs query: "HEAPSTEP\\] tick=" per pod. That reading decides between the candidates still open:

hub scopes (Autofac / TypeRegistry metadata, MessageHub);
payload buffers (Byte[], JsonElement, String);
Roslyn compile state.

Stays open (sev:H) until the step is named and fixed.

Handed over from #5388: GC pauses account for part of the residual Thread Pool execution stalled readings on the current image (ci.9291). On pod 589ff8f895-ghgjt:

13:23:18Z: a 1.05 s stall. Its [LIVENESS] tick (1680) carries +1.25 s gcPause and one gen2 collection; the heap went from 3.36 to 2.22 GiB.
14:16:05Z: a 1.40 s stall. Its tick (1996) carries +0.82 s gcPause, and the tick before carries +0.48 s with one gen2 collection.

No tick OVERRAN on any pod in 20 h. Over 48 h there were 21 OVERRAN ticks, which confirms the query can match. So the pauses on this image are sub-2 s. Details and instruments are in the #5388 comment: #5388 (comment)

Status 2026-09-25 ~15:45Z: the allocator is still not named. The instrument that would name it is now in the merge queue.

feat(liveness): a heap step names what was allocated in it — [HEAPSTEP] (Refs #5555) #5665 ([HEAPSTEP], AllocationByTypeSampler) re-queued. Its ejection cause, the race test reading samples out of the ranked summary, was fixed on-branch at 973af809de. That head's PR run is green, including Automatic review answered, so I removed queue-rejected and re-armed it. The fix still has to be merged, deployed and rolled before any step names its type.
No step of this issue's size on the current image, at coarse resolution. Per-1000 s [LIVENESS] samples over ~30 h on two ci.9291 processes (589ff8f895-ghgjt, -vn49b; data and actions on 6,925 Started sync/ hubs hold ~2.7 GB of a 3.5 GB live heap — population MEASURED, cause NOT established (split from #3321) #3432). The largest sample was 7.81 GiB (ghgjt at 01:57Z 09-25). Neither pod has restarted (Ops/Status/memex-cloud, 15:23Z). A 1000 s cadence can miss a step that rises and falls between samples, so this does not show the steps stopped. It shows only that these two processes did not die of one.
The slow-retention half has been relabelled sev:M on 6,925 Started sync/ hubs hold ~2.7 GB of a 3.5 GB live heap — population MEASURED, cause NOT established (split from #3321) #3432 (floor ~3.3 GiB at 24–30 h). The step is this issue's, and it stays sev:H.

Next reading, once an image carrying #5665 serves memex-cloud: Logs with query: "HEAPSTEP\\] tick=" per pod. That image cannot land until the V57→V58 roll deadlock (#4764) is broken by a governed Reconcile.

#5665 ([HEAPSTEP]) is now merged through the queue. It becomes live on the first memex-cloud image built from a descendant of that merge.

Production diagnostic update, 2026-09-26 17:24Z: a read-only Logs action on memex-cloud ci.9408 asked for [HEAPSTEP] tick= over 120 minutes, returned 17 lines across four pods (no truncation), and landed all 17. The sampler captures multi-GiB allocation bursts: pod memex-portal-deployment-795dd67dcb-b8mf7 at tick 218 grew heap 3.65→4.45 GiB in 10.17 s with 4.21 GiB sampled allocation (System.String 2.24 GiB / 53%, System.Byte[] 1.07 GiB / 25%); at tick 365 it was 3.97→4.53 GiB with 6.23 GiB sampled allocation (String 3.51 GiB / 56%, Byte[] 1.92 GiB / 31%). The newly started 6c7669df84-nbrdx pod showed tick 12 heap 0.44→1.63 GiB with 8.53 GiB allocated in the window, then tick 13 heap 1.63→2.18 GiB with 10.26 GiB allocated. These measurements establish substantial allocation activity on multiple live replicas, but the sampler explicitly reports allocated, not retained, and gives no caller/GC-root attribution. It therefore does not identify the retaining defect or justify a code fix yet; the next decisive instrument is the issue’s GC-root probe (or an equivalent root-attributed capture), not another heap-size sample. The issue remains open.

The first [HEAPSTEP] readings (ci.9408, both portals) name the allocation mix, and a root-cause PR is open: #5767.

Readings. Two Logs actions (Ops/Actions/logs-memexcloud-20260926-heapstep-5555 and Ops/Actions/logs-memex-20260926-heapstep-5555) read 43 and 88 lines over 480 min. Neither was cut. Every step past warm-up has the same mix on every pod of both portals:

System.String 53–56 %
System.Byte[] 25–31 %
JsonDocument 2–4 %

A 10 s window sampled 4–7 GiB. Example: nbrdx tick 164, heap 4.37→5.75 GiB, 7.06 GiB sampled, String 3.86 GiB and Byte[] 2.06 GiB.

The steps at this threshold are allocation churn, not retention. On nbrdx, tick 314 read heap=4.44GiB. Tick 315 ran 2 gen-0, 1 gen-1 and 1 gen-2 collections and read 3.03 GiB. With server GC the gen-0 budget is gigabytes, so GetTotalMemory(false) rises by more than 512 MiB between collections.

The allocator the mix points to. String ≈ 2 × Byte[] plus a JsonDocument means one JSON value was held as UTF-8 and again as UTF-16. ObjectPolymorphicConverter.ReadObject did exactly that for every object-typed value: ParseValue, then GetRawText(), then Deserialize(string), once per nesting level. #5767 reads the common shape ($type first, registered, no metadata) straight from the reader. The repro, one read nested 8 levels with a 400 KB leaf, drops from 4,006,624 to 402,024 bytes allocated. The negative control is red on the old code.

Not established.

The sampler names types, not callers, so this does not prove the converter is the dominant caller in production. Falsifier: the String share on the first image carrying fix(serialization): polymorphic object read — no JsonDocument + UTF-16 copy per nesting level (#5555 HEAPSTEP allocator) #5767. If it stays above 50 %, another caller holds the JSON as text.
This does not explain the earlier +10 GiB steps that were released an hour later (live data, 09-24). No step of that shape appears in today's 8 h window: the largest was +1.42 GiB in one tick, and each was reclaimed by the next gen-2.
Stays open. This is sev:H, so it closes on post-roll verification.

Post-roll allocation reading, memex-cloud, 2026-09-27. #5767 is deployed: its merge f69cac24d07f948db2d0f6e44cd9e31160f1b3f1 is an ancestor of the three current ci.9443 replicas' core 311108bf16a70eee39a6618b36456cf82c58a85f (compare ahead 33, behind zero). Ops/Status/memex-cloud reports one converged generation, 3/3 ready, notScraped:false.

Ops/Actions/verify-5555-memexcloud-20260927-heapstep asked for \\[HEAPSTEP\\] tick= over 240 minutes. It is Done: 50 read, 50 persisted, zero failures, not truncated. I read all 50 persisted entries, covering all three current replicas, timestamps 07:11:33Z–11:05:53Z. String shares range 3–63%; 9 of 50 exceed 50%. Thus the previous comment's String-share falsifier still occurs on the fixed image. This does not invalidate the deterministic converter improvement; it prevents using that improvement as proof that the production allocation problem is solved.

Examples:

Ops/Logs/memex-cloud-1790493223720892159-9cd496-r922l, 07:13:43Z, tick 342: heap 5.99→7.21 GiB in 10.05s, 4.61 GiB sampled; String 2.43 GiB / 53%, Byte[] 1.54 GiB / 33%, JsonDocument 0.04 GiB / 1%.
Ops/Logs/memex-cloud-1790502635878186846-9cd496-qntsh, 09:50:35Z, tick 1266: heap 2.59→3.74 GiB in 10.01s, 2.17 GiB sampled; String 1.28 GiB / 59%, Byte[] 0.72 GiB / 33%.

Stays open. These are allocated bytes, not retained bytes, and the instrument does not name a caller. Another speculative serializer optimization or a larger memory budget would not establish the root of the OOM. The remaining decisive reading is caller/root attribution during the step.

Found a second measured whole-JSON string copy, outside the converter repaired by #5767: MeshNodeStreamCache.DeserializeContent calls GetRawText / ToJsonString before re-typing every emitted query node.

The real-hub control allocates 1,024,616 bytes for a 512,000-byte leaf, through either JsonElement or JsonObject. Reading the JSON representation directly reduces this to 512,504 / 512,696 bytes, preserving typed content. Both allocation cases fail against the previous code; 11 focused allocation, degradation-sink and collectible-type recovery cases pass with the change, as do Release warnings-as-errors builds and 11 documentation integrity checks.

PR #5803 carries the repair and the investigation record in Doc/Architecture/WhichKindOfSilence. It is still in CI and has not reached production.

The earlier post-roll HEAPSTEP readings remain allocation-type samples, not caller or retained-root attribution. A String share above 50% cannot alone prove another duplicate: ordinary UTF-8 input plus its materialized UTF-16 strings can contribute that mix. This query method does independently exhibit a full-value copy. The broader issue stays open pending the supported roll, typed-query verification and new production readings.

Follow-up read-only sample completed 2026-10-10 03:14Z: action Ops/Actions/logs-memexcloud-20261010-0313-heapstep-5555 queried memex-cloud for the prior 60 minutes (02:14:45–03:14:45Z); 5 lines read/landed, 0 failures, not truncated. All five are real [HEAPSTEP] events on the running 3.1.10365 d9cd97 generation:

p9nw4, 02:26:12Z: +0.68 GiB; sampled 1.96 GiB, led by String 1.12 GiB and Byte[] 0.73 GiB.
p9nw4, 02:30:33Z: +0.58 GiB; sampled 3.64 GiB, led by String 2.04 GiB and Byte[] 1.30 GiB.
p9nw4, 02:33:54Z: +0.64 GiB; sampled 1.90 GiB, led by String 1.08 GiB and Byte[] 0.67 GiB.
p9nw4, 02:37:13Z: +0.56 GiB; sampled 0.57 GiB, led by String 0.34 GiB and Byte[] 0.20 GiB.
62jkm, 03:06:20Z: +0.66 GiB; sampled 0.41 GiB, led by String 0.25 GiB and Byte[] 0.12 GiB.

This adds post-roll heap-step observations, not a clean window. [HEAPSTEP] reports allocation volume, not retention or the producing allocator/callsite; these type totals do not identify the allocator, so I am not proposing a fix from them.

Follow-up read-only sample at 04:15Z: action Ops/Actions/logs-memexcloud-20261010-0414-heapstep-5555 queried memex-cloud for 03:14:58–04:14:58Z; 6 lines read/landed, 0 failures, not truncated. All six are [HEAPSTEP] events on the running 3.1.10365 d9cd97 generation, across ngmng, 62jkm, b2bhw, and p9nw4; per-step heap deltas range +0.63 to +1.13 GiB over about 10 seconds, and sampled allocation totals range 0.07–5.83 GiB. The samples show varying object types (including String/Byte[], Entry[String][], plus reflection/Autofac types in some steps), but still no producing allocator or callsite. This one-hour observation is not the required clean window, and it does not support attributing a fix.

2026-10-10 ~05:05Z re-check (memex and memex-cloud): no OOM, but the window is too short. Next check at 2026-10-11 01:45Z or later.

Both portals rolled to 3.1.10365 (core 479c9b72) on 2026-10-09 at about 22:30Z.

	memex	memex-cloud
Sample (`notScraped: false`)	`sample-memex-20261010-0500-oom-window`: 3/3 ready, generation `d49477bf6`, 0 restarts. Pods started 22:30:37Z, 22:34:04Z and 22:37:17Z.	`sample-memex-cloud-20261010-0500-oom-window`: 4/4 ready, generation `7b55d9cd97`, 0 restarts. Pods started 22:30:21Z, 22:31:43Z and 22:33:05Z, plus `p9nw4` at 01:41:42Z.
`OutOfMemory\|[HEAPSTEP]`, 22:20Z to 05:00Z, not cut	19 lines, 0 OOM (4 non-HEAPSTEP lines only quote an older query string)	44 lines, 0 OOM, all HEAPSTEP
HEAPSTEP peak	3.01 GiB (`cs7bf`, 02:05Z)	5.06 GiB (`ngmng` tick 1103, 01:38Z) and 4.96 GiB (`62jkm` tick 1119, 01:38Z)
HEAPSTEP latest	2.01 GiB (`lkvl6`, 04:46Z)	3.28 GiB (`62jkm`, 03:36Z) and 2.81 GiB (`ngmng`/`b2bhw`, 03:36Z)

memex-cloud p9nw4. This pod joined the same generation at 01:41:42Z, about 3 minutes after the 4.96/5.06 GiB steps on 62jkm and ngmng. The lifecycle read (Ops/Actions/logs-memex-cloud-20261010-0505-lifecycle, 22:00Z to 05:00Z) shows no Application is shutting down line from any 7b55d9cd97 pod. The 2026-10-09 19:58Z sample showed 3 replicas, and desired is 4 now. That fits a scale-out, not a replacement, but I did not establish whether it was an HPA scale-up or a pod that was killed without a graceful shutdown (an OOMKill leaves no app log line). restarts=0 holds on all four pods.

Positive control. The 6.5-day OutOfMemoryException read on memex failed with a Loki timeout, so this round has no positive control. The memex-cloud peak of about 5 GiB within 3 h of boot is below the 7.2 GiB seen on the pre-fix image, but it is still a multi-GiB step pattern.

Not closing. The single-generation window is about 6.5 h (memex) and about 3.3 h (memex-cloud, counted from p9nw4). The 24 h window completes at 2026-10-10 22:37Z for memex and 2026-10-11 01:42Z for memex-cloud, if neither rolls first.

Fresh read-only memex-cloud sample at 06:16Z: Ops/Actions/logs-memexcloud-20261010-0615-heapstep-5555 queried 05:15:55–06:15:55Z; 16 lines read/landed, 0 failures, not truncated (15 [HEAPSTEP] entries and one Application started). All heap steps are from the current 3.1.10365 d9cd97 generation. Per-step heap deltas range +0.52 to +1.16 GiB over roughly 10 seconds; sampled allocation totals range 0.38–7.24 GiB. The current status is 5/5 ready, Degraded; a new xb6pt pod started at 05:44:37Z (its Application started line is 05:45:40Z), so the previous projected cloud window based on the 01:41 pod start does not cover every currently running pod. I am not inferring whether this was scale-out or replacement. The samples show object types only (String/Byte[] often lead; one step has Roslyn symbol types); they do not identify a producing allocator/callsite or retained heap. This is not a clean window and does not support a fix attribution.

Fresh read-only memex-cloud Logs action at 07:17Z, window 06:17:40–07:17:40Z: 25 lines read and landed, 0 failed, not truncated (16 [HEAPSTEP], 9 Application started). Fourteen heap-step records belong to the preceding d9cd97 generation; two are from the newly rolled 8cbcc7 generation (3.1.10411), at 07:11:12Z and 07:13:16Z. The new-generation events report sampled allocations of 8.93 GiB and 3.89 GiB over ~10s, with heap deltas +0.59 and +0.66 GiB. Their leading allocated types are System.String (35% and 49%) and System.Byte[] (21% each); the first also lists SubjectDisposable<ChangeFeedGap>[] and RuntimeMethodInfoStub. The event explicitly says “Allocated, not retained.” This identifies candidate allocated object types from real post-roll events, not the producing allocator/callsite or retained heap, so it does not support a root-cause fix yet. The selected query returned no OOM/regen lines, which I am not treating as a clean result.

Fresh read-only Logs action (2026-10-10 08:16Z, window 07:16–08:16Z): 39 lines landed, 0 failed, not truncated; 27 [HEAPSTEP] and 12 startup records. On the new 3.1.10416 pod memex-portal-deployment-85587f8869-prgnp, real events at 08:09:29Z and 08:15:49Z sampled allocations of 6.21 GiB and 3.05 GiB over ~10s, with heap deltas +0.84 GiB and +0.82 GiB. System.String and System.Byte[] are the leading allocated types (29%/18%, then 55%/38%); both lines explicitly say “Allocated, not retained.” This still does not identify a producing allocator/callsite or retained heap, so I am not proposing a fix.

Fresh read-only Logs actions for 08:18:29–09:18:29Z landed 43 matching lines across memex-cloud (10) and memex (33), with zero failures and no truncation. New 3.1.10429 [HEAPSTEP] events include memex-cloud 09:02:40/09:02:50 (heap +0.90/+0.68 GiB; sampled allocation 11.07/5.57 GiB) and memex 09:10:03/09:10:13 (heap +0.57/+0.86 GiB; sampled allocation 2.69/7.76 GiB). The leading allocated types are System.String and System.Byte[], with Entry[System.String][] also prominent. Every line says “Allocated, not retained.” These real post-roll samples still do not identify a producing allocator/callsite or retained heap, so I am not proposing a fix.

Fresh read-only post-10442 sample (Logs window 2026-10-10 11:23–12:23Z): the new memex 3.1.10442 pod reports [HEAPSTEP] at 12:16:04Z (+0.71 GiB heap/10s; 3.74 GiB sampled allocation; System.String 53%, System.Byte[] 39%). A new memex-cloud 3.1.10442 pod reports [HEAPSTEP] at 11:58:11Z (+1.39 GiB heap/10s; 6.44 GiB sampled allocation; System.String 56%, System.Byte[] 37%). Both explicitly say “Allocated, not retained.” These real samples still do not name the producing allocator/callsite or retained heap, so no fix is proposed.

Fresh real [HEAPSTEP] evidence from memex-cloud at 2026-10-10 13:16:18Z: tick 198, heap 2.15 to 3.44 GiB (+1.28 GiB), 8.62 GiB sampled allocation in the window; System.String 4.39 GiB (51%) and System.Byte[] 2.99 GiB (35%) were the leading allocated types. The event explicitly says allocated, not retained, and calls the leading type a candidate only; it does not identify a producing allocator or callsite. No fix is proposed from this evidence.

New real [HEAPSTEP] evidence, memex pod memex-portal-deployment-59455c46c5-mcdgz on 3.1.10450, 2026-10-10 14:19–14:20Z: two steps sampled 1.68 GiB and 3.62 GiB allocated; the leading types were System.String (54%, then 46%) and System.Byte[] (40% both times). The event explicitly describes allocated, not retained, and calls the leading type only a candidate. This does not identify a producing allocator/callsite, so I am not proposing a fix from it.

Fresh real [HEAPSTEP] event: memex-cloud at 2026-10-10T14:31:37Z, pod memex-portal-deployment-868574bc48-86gkq, heap 2.02→2.58 GiB (+0.56 GiB) over 10 s; sampled allocation 0.90 GiB. The sample is System.String 0.50 GiB (56%) and System.Byte[] 0.33 GiB (36%), with other types small. The event explicitly says allocated, not retained, and labels the leading type only as a candidate for what the step holds. It does not identify the producing allocator/call site or retained owner, so no fix is proposed.

Fresh real [HEAPSTEP] sample from memex-cloud, pod memex-portal-deployment-5dd55769d4-wsrtl, 2026-10-10 17:34:08Z: heap 3.77→4.92 GiB (+1.15 GiB) over 10.16s; sampled allocation 11.95 GiB in the window. Leading allocated types were System.String 6.50 GiB (54%) and System.Byte[] 4.05 GiB (34%). The event explicitly measures allocated, not retained, and does not identify the producing allocator or callsite. No fix is proposed from this evidence.

Closing: 0 `OutOfMemoryException` in 72 h on both instances, and the heap steps now have a named producer

The closing reading is the one on #6161 (same family, same drivers, same windows): 72 h to 2026-10-11 10:57Z, (?i)OutOfMemory returns 0 real lines on memex (Ops/Actions/logs-memex-20261011-1050-oom-72h, 4 lines that only quote an earlier query) and 0 lines on memex-cloud (Ops/Actions/logs-memexcloud-20261011-1050-oom-72h). Of 334 portal pods, one restarted in place, a boot wedge whose last recorded heap step was 1.16 GiB. 0 [DISPOSE-WEDGE] in 36 h. The 24 h single-generation condition cannot be met on instances that roll on every platform build (memex-cloud rolled twice in the hour of this session), so this is a multi-generation reading and says so.

What produces the multi-GiB [HEAPSTEP] steps. The last three comments here recorded String about 55 % and Byte[] about 35 % with no producer. A read-only in-process census on memex-cloud at 2026-10-11 11:01Z (generation 688f5555d6, image 3.1.10517) names it:

pod	started	uptime	hubs	node hubs	`sync/` hubs	last-GC heap
`8f2g5`, first of its generation	10:27:56Z	32.9 min	4,795	1,059	3,736	5,563 MiB (1,779 fragmented), working set 8,317 MiB
`pzvwj`	10:29:28Z	30.9 min	670	101	569	1,303 MiB

Same instance, same image, 90 seconds apart, and a factor of ten in hubs and four in heap.
The 1,059 node hubs on the first replica are boot work, not traffic: 403 two-segment addresses (NodeType definitions), 128 partition roots, 115 …/_Policy, 115 …/_Entitlements, 66 …/_Activity, 43 …/_GitSync. Its bake had finished at 10:30:36Z with compiled=0 alreadyBaked=420.
About 5 MB of live heap per node hub. Each carries its own scope, type registry, workspace and three or four sync/ hubs, which is why the sampled allocation is System.String, System.Byte[], Entry[System.String][] and Autofac's IResolvePipelineBuilder handlers and MiddlewareDeclaration.
The highest landing points of the last 36 h fit that: 6.83 GiB on 449b98-l5zjj at tick 92, fifteen minutes after boot, and 5 to 6 GiB at ticks 40 to 280 on more than a dozen other pods in their first 45 minutes (Ops/Actions/logs-memexcloud-20261011-1050-heapstep-36h, 499 lines, not cut). The limit is 16 Gi.

Not established. Whether those boot-activated hubs retire once idle: the replica was replaced by the next roll about 20 minutes after the reading, so there is no second reading on the same process. Which boot step activates each class. The one step that does not fit the boot shape is bc87bb-z77kg at 7.09 GiB on tick 1148, about three hours into its process; it was not examined.

Where it goes. This is headroom on a 16 Gi limit, not exhaustion, so it does not keep a sev:H open. It is filed into triage with the readings above (rbuergi/Feedback/20261011-first-replica-boot-hub-fanout on memex.systemorph.com), and the tables are committed in Doc/Architecture/SyncHubPopulation §9 (PR #6487).

The AnalyzeDump of 2026-10-11 07:59Z (Ops/Actions/analyzedump-memex-cloud-20261011-ltlwc-2) was read for this: it is the thread report of a pod wedged at boot (#6391): sections eeversion, threadpool, syncblk, clrthreads and dumpasync, 91 managed threads in 86 stacks. It carries no heap statistics, so it names no allocator.

_{Claude Opus 5.5 (agent session). Read-only apart from Logs and Sample InstanceActions on the control instance and a census script in the operator's own partition.}

@rbuergi

(re-posted 2026-10-11; originally by @rbuergi on 2026-10-07)

What is growing now: a NodeType bind/recompile loop on `Store/Plugin`, amplified by recycle jobs. Fixes: #6261 (core) and MeshWeaver.Plugins#3109

All readings below were taken on 2026-10-07, about 16:00–16:15Z, on memex.systemorph.com. They come from governed Logs actions and read-only scripts under rbuergi/Script/oom-5555-*.

1. The type node is rewritten in a loop. Store/Plugin (NodeType) went from version 12083 (10-06 17:00Z) to version 18986 (10-07 13:22Z), roughly 6,900 writes. They came in bursts: 1,116 and 1,295 per hour on 10-06 at 22Z and 23Z, then 1,927 and 2,058 per hour on 10-07 at 08Z and 09Z. store.mesh_node_history shows one repeating cycle: Ok(N) → Ok(N+1) → Pending → Ok(lastCompiledVersion = the Pending version). Each cycle has the same latestAssemblyMvid 1d9f4d8e… and the same hash 1db01ff9e178; only the v{N} part of the path changes. On memex.meshweaver.cloud the same type is at version 15859, so the same loop runs there. On client-b it is at version 207, so the loop is not running there.

2. Why the cycle never ends. Ops/Actions/logs-oom-storeplugin-bind-20261007 returned 1,000 lines (cut at the limit). The same line appears 604 times on one pod between 09:46 and 10:11Z:
EnrichWithNodeType: the recorded build of Store/Plugin (collection=local, version=18979, path=Store_Plugin/v18979-c003e001-1db01ff9e178.dll) still does not load … Failed to load assembly at /data/assembly-cache/Store_Plugin/v18979-c003e001-1db01ff9e178.dll — No file at '/data/assembly-cache/Store_Plugin/v14766-c003e001-1db01ff9e178.dll'.
Each plugin root also logs Overlay self-heal: instance '<root>' is stuck on NodeType 'Store/Plugin' AGAIN after 13 self-heal(s).
The cause is CompilationCacheService.FindLiveContextOfSameBuild. It hands a read of the present v18979 file to an older live context that has the same MVID, built over v14766. That context never loaded its assembly, and its file has since been deleted. Each self-heal recompile adopts identical bytes under a new version, and the read is aliased back to the same dead context.

3. The loop fans out into recycle jobs. AddRecycleOnNewBuild keyed on the raw LatestAssemblyPath, so it read every re-adoption as a new build. Over 31 hours the operator/ops queue received 7,084 recycle jobs, mirrored in instances/memex. That is 14,340 Hosting/Job rows holding 21.7 MB of JSON, plus 12,247 JobSeal rows. 2,126 of the jobs were for Store/Plugin alone. Every queue pass reads all of its jobs about 4 times.

4. Heap evidence. Ops/Actions/logs-oom-heapstep-memex-20261007-1520 covered 14:03–16:03Z: 105 lines, not truncated. Every sample leads with String and Byte[]. Entry[System.String][] appears in 95 samples, ReadStackFrame[] in 64, JobContent in 32, and Roslyn/PE types appear occasionally. One kdk28 sample allocated 10.95 GiB in 10 s. The crash agent's reading for pod 65f6466887-5cx77 was a flat 11.3–11.6 GiB heap with GC taking 56% of wall time from 09:31 to 10:03Z, and 65–93% from 09:52 to 09:56. That window falls inside the loop burst.

Fixes

Core fix(compiler): never alias a read to a same-MVID load context that can no longer load its build (#5555) #6261: NodeAssemblyLoadContext.CanLoadItsBuild (the assembly is loaded, or its file exists) now gates the same-build alias. ScanPinSupersessionTest.AReadIsNeverAliasedToASameBuildContextThatCanNoLongerLoadIt fails on the old resolver and passes with the fix. Its control test keeps the in-memory reuse working.
Plugins#3109: the recycle rule now keys on the bytes (LatestAssemblyMvid, or the path minus v{N}-). Its in-mesh test includes a raw-path negative control.

Not established

No dump was taken, so "this loop holds the heap" rests on timing and the allocation mix, not on dominators.
Why the v14766 context never loaded, or lost, its assembly, and which sweep deleted the file.
The 09-19 and 09-23 memex-cloud bursts are still unattributed.
client-b's three managed OOMs (ci.9887: 10-06 01:07Z, 10-06 12:42Z, 10-07 12:49Z) are not explained by this loop, because it does not run on client-b.

If a heap census is needed before the next roll: dumps written to the memex-dumps emptyDir are lost on every roll, so a dump has to be copied out while the pod is alive. Run dotnet-gcdump collect -p 1 -o /dumps/<pod>-<utc>.gcdump inside the portal container on the replica whose [HEAPSTEP] shows ≥ 8 GiB (the .gcdump is a full-census graph up to 10M objects; for more, dotnet-dump collect -p 1 --type Heap), then kubectl cp it off the node before any roll or Reconcile. That is break-glass cluster access, so the maintainer has to run it or authorise it.

This stays open until a post-roll reading on an image carrying both fixes shows that the Store/Plugin version stops climbing, that no No file at lines appear, and that there is no multi-GiB [HEAPSTEP] plateau.

Navigation Menu

Repository navigation

MessageService DrainLoop throws OutOfMemoryException during hub delivery (recurrence of #4824) #5555

Evidence

A 9.7 GiB burst in 107 seconds, on a process about 6 minutes old. This was not the slow leak.

1. The process that threw was on a current image and had just started

2. Its own `[LIVENESS]` line shows the heap curve (`heap=` is `GC.GetTotalMemory(false)`, logged every 10 s)

3. The stack shape carries no signal

4. Leads, NOT established

Next reading (cheap, read-only, no dump)

The multi-GiB step is not a single-pod startup event. It recurs, lands on several replicas in the same minute, and lines up with replicas leaving or joining

1. The instrument and the denominator

2. The step recurs on the same image, far from boot

3. Replicas are dying from other causes, and each death is a candidate trigger

4. What this changes about the reading on this issue

Not established

The allocator is still not named. #5665 adds the in-band reading that would name it. One causal arrow on this issue probably points the other way.

1. The 01:00Z "replica joined" is more likely the step's effect than its cause (not established)

2. What else I ruled out while reading the code

3. Why no fix, and what #5665 does instead

46 remaining items

2026-10-10 ~05:05Z re-check (memex and memex-cloud): no OOM, but the window is too short. Next check at 2026-10-11 01:45Z or later.

Closing: 0 `OutOfMemoryException` in 72 h on both instances, and the heap steps now have a named producer

What is growing now: a NodeType bind/recompile loop on `Store/Plugin`, amplified by recycle jobs. Fixes: #6261 (core) and MeshWeaver.Plugins#3109

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

MessageService DrainLoop throws OutOfMemoryException during hub delivery (recurrence of #4824) #5555

Description

Evidence

Activity

systemorph-com commented on Sep 23, 2026

rbuergi commented on Sep 23, 2026

A 9.7 GiB burst in 107 seconds, on a process about 6 minutes old. This was not the slow leak.

1. The process that threw was on a current image and had just started

2. Its own [LIVENESS] line shows the heap curve (heap= is GC.GetTotalMemory(false), logged every 10 s)

3. The stack shape carries no signal

4. Leads, NOT established

Next reading (cheap, read-only, no dump)

rbuergi commented on Sep 23, 2026

rbuergi commented on Sep 24, 2026

The multi-GiB step is not a single-pod startup event. It recurs, lands on several replicas in the same minute, and lines up with replicas leaving or joining

1. The instrument and the denominator

2. The step recurs on the same image, far from boot

3. Replicas are dying from other causes, and each death is a candidate trigger

4. What this changes about the reading on this issue

Not established

rbuergi commented on Sep 24, 2026

rbuergi commented on Sep 24, 2026

The allocator is still not named. #5665 adds the in-band reading that would name it. One causal arrow on this issue probably points the other way.

1. The 01:00Z "replica joined" is more likely the step's effect than its cause (not established)

2. What else I ruled out while reading the code

3. Why no fix, and what #5665 does instead

rbuergi commented on Sep 25, 2026

rbuergi commented on Sep 25, 2026

rbuergi commented on Sep 25, 2026

rbuergi commented on Sep 26, 2026

rbuergi commented on Sep 26, 2026

rbuergi commented on Sep 27, 2026

rbuergi commented on Sep 27, 2026

46 remaining items

rbuergi commented on Oct 10, 2026

rbuergi commented on Oct 10, 2026

rbuergi commented on Oct 10, 2026

2026-10-10 ~05:05Z re-check (memex and memex-cloud): no OOM, but the window is too short. Next check at 2026-10-11 01:45Z or later.

rbuergi commented on Oct 10, 2026

rbuergi commented on Oct 10, 2026

rbuergi commented on Oct 10, 2026

rbuergi commented on Oct 10, 2026

rbuergi commented on Oct 10, 2026

rbuergi commented on Oct 10, 2026

rbuergi commented on Oct 10, 2026

rbuergi commented on Oct 10, 2026

rbuergi commented on Oct 10, 2026

rbuergi commented on Oct 11, 2026

Closing: 0 OutOfMemoryException in 72 h on both instances, and the heap steps now have a named producer

rbuergi commented on Oct 11, 2026

What is growing now: a NodeType bind/recompile loop on Store/Plugin, amplified by recycle jobs. Fixes: #6261 (core) and MeshWeaver.Plugins#3109

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions

2. Its own `[LIVENESS]` line shows the heap curve (`heap=` is `GC.GetTotalMemory(false)`, logged every 10 s)

Closing: 0 `OutOfMemoryException` in 72 h on both instances, and the heap steps now have a named producer

What is growing now: a NodeType bind/recompile loop on `Store/Plugin`, amplified by recycle jobs. Fixes: #6261 (core) and MeshWeaver.Plugins#3109