Repository navigation
StackOverflowException kills the portal: Rx Merge(maxConcurrent) recurses once per queued inner when inners complete synchronously (export during a roll) #5649
Description
What happened
Two memex-cloud replicas died of an uncatchable StackOverflowException during the ci.9287 roll on 2026-09-24:
| pod | death | evidence |
|---|---|---|
memex-portal-deployment-76cf776847-5hflx |
06:49:47Z | stderr carries a long run of repeating MessageHub.WrapWithCancelOnDispose frames (Logs action Ops/logs-memexcloud-20260924-so-5hflx-nonsystem) |
memex-portal-deployment-76cf776847-v4txp |
06:56:01Z | [createdump] … Unwind: exception type System.StackOverflowException; Stack overflow. then the frames below (Logs actions Ops/logs-memexcloud-20260924-stackoverflow-v4txp, …-so-v4txp-nonsystem, …-so-v4txp-wrapcount) |
The v4txp stderr trace, innermost first, is one repeating block over a single MessageHub.HandleCallbacks → MessageService.DrainLoop → DrainOne at the bottom:
Merge`1+ObservablesMaxConcurrency+_+Inner → Producer<ValueTuple> → Select → CombineLatest
→ Catch → Select → Timeout → Take → Select → Defer / Finally / Do.OnNext
→ MessageHub.<WrapWithCancelOnDispose> → SubscribeSafe → AsyncSubject (already terminated)
→ Timeout → Catch → BasicProducer / ReturnImmediate → CombineLatest+SecondObserver → Merge.Inner → …
A stream="stderr" read of ObservablesMaxConcurrency frames alone was CUT at its limit of 50, so the recursion was at least 50 levels deep; the exact depth was not measured. No Repeat N times header was printed. Both deaths fell seconds after an MCP export of Ops/Logs (~2,200 nodes) dropped, inside the roll.
Root cause
Rx's Merge(IObservable<IObservable<T>>, int maxConcurrent) subscribes the next QUEUED inner from inside the previous inner's OnCompleted, on the same stack. When queued inners complete synchronously during Subscribe, each completion subscribes the next — stack depth proportional to the queue length.
The frames match MeshOperations.GetNodeCollectionConfigs exactly (two ReadHub.Observe(GetDataRequest) legs, each .Take(1).Timeout(20s).Select(…).Catch(→ Return), CombineLatest, projected to (NodePath, Configs)) under .Merge(NodeCopyHelper.DefaultBatchSize) in the export. During the roll the reading hub reached ShutDown, and MessageHub.GetOrAddResponseSubject hands out an already-faulted AsyncSubject at that RunLevel — so every queued lookup terminated synchronously on subscribe, the Catch turned it into an immediate value, and the dequeue recursed through the queue.
The same shape exists at every bounded fan-out: 23 Merge(n) sites in src/ + memex/ (recursive-delete pre-validation, static-repo import, GitHub sync, package install, SEO sitemap).
Deterministic repro
BoundedMergeStackDepthTest (Messaging.Hub.Test): export-shaped legs whose response subject is pre-faulted, queued behind 4 pending ones. With the bare operator the last queued leg is subscribed 1,363 frames deep behind a queue of 20 and 8,903 behind a queue of 150 (~58 frames per queued leg) — linear in N. With the fix both are equal.
What is NOT established
- The exact recursion depth at death, and whether any other bounded fan-out was also recursing.
- That the 5hflx trace is the export lookup rather than another
Merge(n)site — only the repeatingWrapWithCancelOnDisposeframe was read there.
Activity
rbuergi commentedon Sep 24, 2026
Correction to the body: the bounded fan-out count is 25 code sites in
src/+memex/(not 23) — the ratchet guard found one inmemex/Memex.Portal.Shared/Api/SeoEndpoints.csthat a grep missed. Fix: #5651 (MergeBounded, all 25 converted, deterministic depth test with negative control 1,363 → 8,903 frames).rbuergi commentedon Sep 24, 2026
#5651 merged (73932e7 head). Awaiting a roll: stays open until memex-cloud runs an image carrying MergeBounded and a large export / roll shows no new
Unwind: exception type System.StackOverflowException(policy severity-closes-on-verification). Follow-up: MeshWeaver.Plugins has 11 bareMerge(n)sites of its own, convertible once a sealed platform set carries MergeBounded.rbuergi commentedon Sep 24, 2026
MeshWeaver.Plugins has 11 bare
Merge(n)sites. Converting them toMergeBoundedis on hold until a platform set that carries #5651 is the one Plugins PRs resolve.I measured it on Plugins PR run 35978371707, in the "Resolve the released platform" job. PRs resolve 3.0.0-ci.9291 = core
140c5fb7a, andaf2d7993(the #5651 merge) is not an ancestor of it:git merge-base --is-ancestorreturns 1, and there are 24 commits between them. A conversion now would fail with CS1061 on the PR lane.The sites on Plugins
mainat5e084544f. Each one is a bounded fan-out whose inners can complete synchronously, so each has the same recursion shape as #5649:Hosting/IssueClassificationRun/Source/ModuleSet.cs.Merge(4)Hosting/InstanceAction/Source/InstanceActionControlPlane.csbounded.Merge(maxConcurrent)Hosting/Deployment/Source/PlatformPinUpdater.cs.Merge(maxConcurrent: 2)Store/Publishing/Source/Provisioning.cs.Merge(MaxConcurrentCompiles)Store/Publishing/Source/ModuleDependencies.cs.Merge(4)src/MeshWeaver.InstanceSync/InstanceSyncWorker.cs.Merge(options.PushConcurrency)src/MeshWeaver.InstanceSync/InstanceSyncWorker.cs.Merge(options.PushConcurrency)src/MeshWeaver.InstanceSync/InstanceSyncWorker.cs.Merge(options.PushConcurrency)src/MeshWeaver.ContentCollections.Indexing.Graph/ContentIndexingObserver.cs.Merge(MaxConcurrentUploadIndexing)src/MeshWeaver.AI/AiContentDiskWriter.cs.Merge(4)src/MeshWeaver.AI/AiSourcesInstallHook.cs.Merge(4)Five of them (ModuleSet, InstanceActionControlPlane, PlatformPinUpdater, Provisioning and ModuleDependencies) are in-mesh module sources, so only the compile-check lane compiles them. Plugins also has no counterpart of core's ratchet guard over
Merge(n), so it should be added in the same follow-up.Not established: whether any of these is actually recursing in production. They were found by reading the source; I did not read any logs for them.
rbuergi commentedon Sep 25, 2026
memex-cloud evidence for the last 24 h: 2 recurrences, both before the 07:20Z roll, and the running image is still pre-fix
Ops/logs-memexcloud-20260925-unwindon memex.meshweaver.cloud (read-onlyLogs) has[createdump] Unwind: exception type System.StackOverflowExceptionon podsmemex-portal-deployment-…776847-5hflx(~06:49Z) and-v4txp(~06:56Z) on 2026-09-24. There are no further StackOverflow dumps after that point in the window.memex-cloud now runs
3.0.0-ci.9291, core140c5fb7(committed 2026-09-24 07:08Z). That is not a descendant of #5651 (af2d7993, 08:13Z), so the fix is not deployed there. The absence since 07:20Z is not verification.rbuergi commentedon Sep 25, 2026
Status 2026-09-25 15:25Z: the fix is merged but neither portal runs it yet. Leaving this open.
/api/versioncoreaf2d799301)?140c5fb7ae(ci.9291)git log 140c5fb7ae..origin/mainlists it39f49494eb(ci.9218)Ops/Status/memex-cloud(sampled 15:23Z) shows a roll to3.0.0-ci.9349in progress,converged: false. Its one new pod (6f6cb589d9-5bx64) has 56 restarts and refuses/health. That fits theDbVersionGateV57→V58 deadlock recorded on #4764: the routed Roll plan has no migration step. So the only thing blocking verification is a production act, not code. The act is a governed Reconcile ofDeployments/memexand thenDeployments/memex-cloud, which runs the migration Job to V58.The closing condition is unchanged: a portal runs an image that descends from
af2d799301, and a large export or roll then shows no newUnwind: exception type System.StackOverflowException. The PluginsMerge(n)follow-up is not established here.rbuergi commentedon Sep 26, 2026
Post-roll verification, memex.systemorph.com, 2026-09-26 ~05:55Z. memex serves
3.0.0-ci.9332= core4028fd6468(/api/version), Plugins half1470fbf3(CD run 9332 portal-ai jobHEAD is now at 1470fbf; same ref as the/healthpublication-seal line). The DB is at V58:memex-migration-63loggedDatabase migration completed. Version: 58at 2026-09-25 17:58:03Z. The roll is not converged:Ops/Status/memexat 05:48Z reads 1/3 ready; only5dbb7df97b-dktrd(booted 04:06:39Z) serves. So every post-roll window below is about 1 h 50 min on one serving replica. All reads areLogsInstanceActions underOps/Actions/logs-memex-20260926-postroll-*.Still open: the fix is live on memex, and the trigger has not happened there.
af2d799301(fix(rx): bounded fan-outs dequeue through the trampoline — MergeBounded replaces bare Merge(n) (StackOverflow, #5649) #5651) is an ancestor of4028fd6468.Ops/Actions/logs-memex-20260926-postroll-unwind(Unwind: exception type|Stack overflow|Gathering state for process, 300 min, not cut) returned 1 line. It is a[createdump] Gathering stateat 02:08:15Z on56fbdcd48f-cbms9, which is the old ci.9218 image. That line is the positive control: the instrument does see dumps in this window. There are 0 dumps on any ci.9332 pod.exportinside a roll. Nothing like that has run against ci.9332. A quiet 1 h 50 min only shows that the trigger did not occur.memex-cloud, read 06:00–06:03Z (the coordinator reported it rolled):
/api/version= core7bc7ab26f0(ci.9349), Plugins half5e8b85f9(CD run 9349 portal-ai job).memex-migration-49logged[Rehearsal] v58 … → 7 row(s) across 1 target(s)at 05:53:15Z andDatabase migration completed. Version: 58at about 05:54:20Z. TheSampleat 06:00:26Z shows the roster mixed: 3 ci.9349 pods ready, and 5 ci.9291 pods (589ff8f895-*) still ready and serving. So every ci.9349 reading below covers minutes, not hours.memex-cloud:
af2d799301is in7bc7ab26f0.…memexcloud-20260926-postroll-unwind(240 min) = 0 dumps, so there is nothing to score yet.Closes when: once memex-cloud has converged on ci.9349, a large export or a roll shows no new
StackOverflowExceptionunwind.rbuergi commentedon Sep 27, 2026
Production verification completed on memex-cloud, 2026-09-27.
Ops/Status/memex-cloud, sampled 10:57:54Z:notScraped:false, one generation, converged, 3/3 ready. Every replica serves ci.9443 / core311108bf16a70eee39a6618b36456cf82c58a85f. GitHub compare from fix(rx): bounded fan-outs dequeue through the trampoline — MergeBounded replaces bare Merge(n) (StackOverflow, #5649) #5651'saf2d799301reports ahead 253, behind zero, so all sampled replicas carry the fix.@Ops/Logscompleted at 11:04:07Z. The ZIP CRC check found no bad entry; its manifest contains 18,428 nodes under Ops/Logs, with zero content-collection files. This is larger than the original approximately 2,200-node trigger. I did not deliberately overlap the export with shutdown; the existing deterministic pre-faulted-subject regression test covers that edge.Ops/Actions/verify-5649-memexcloud-20260927-unwind: 1,440-minute query forUnwind: exception type|Stack overflow|Gathering state for process, Done, zero records, no truncation or landing failures....-startup: 121 startup lines read and all 121 persisted, zero failures, not truncated. An actual persisted example isOps/Logs/memex-cloud-1790447648778324741-9f5d5f-4mpxz(2026-09-26 18:34:08Z)....-postexport-unwind: same unwind predicate over ten minutes, Done at 11:05:14Z, zero records, no truncation or landing failures.This meets the closing condition recorded above: convergence on an image containing the fix, then a large export with no new stack-overflow unwind. Closing the core crash as completed. The Plugins bounded-fan-out conversion and ratchet remain separately tracked in Plugins PR #2420, currently in CI; this does not claim those sites are already deployed.
The existing architecture page now records these exact instruments and limits in #5798. The broad export-trace diagnostic was truncated and is not used for the zero-unwind verdict.