Bake seal β€” the hub that stops answering is portal/nodeops

The CD job Plugins: bake + seal the publication for this identity / Bake + publish NodeType assemblies to portal storage fails intermittently. It is filed as #2543, "per-node hubs stop answering mid-bake".

The per-node hubs are not where the silence starts. Every per-node owner in a failing run is RunLevel=Started with an EMPTY queue, waiting on the one hub they all share. This page records what was measured, so the next session does not re-derive it.

🚨 The one sentence

portal/nodeops-{meshId} is the mesh's single node-CRUD execution hub β€” every CreateNodeRequest and CreateOrUpdateNodeRequest in the entire mesh is serialised on its one action block β€” and during a bulk node-repo install it stops draining for tens of seconds. Everything downstream then reports its own bound expiring, which is what makes the failure look like N unrelated defects.

What actually fails the gate

Not the write wedge the issue is named after. The verdict, in 6 of 6 failing seals measured on 2026-09-03, is byte-identical:

[FAIL] Hosting (counts unavailable β€” the pipeline threw before the install reported)
    install: [install] TimeoutException: The operation has timed out.
GATE FAILED β€” install: Hosting

"The operation has timed out." is TimeoutException's DEFAULT message, i.e. Rx's own .Timeout(...) β€” here PluginGateRunner's InstallTimeout (10 minutes, tools/MeshWeaver.PluginTester/PluginGateRunner.cs). The hub's RequestTimeout throws a different, richly-worded TimeoutException ("No response received in hub X within 00:01:00 …"), so the message alone tells you which bound fired.

Measured, every failing run, to the second:

install starts adoptions done install ends
PASS (run 33727875031) 07:55:24 07:56:43 07:57:15 β€” installed (140 written)
FAIL (run 33728545478) 07:57:12 07:58:46 08:07:12 β€” exactly T+600 s, TimeoutException

The same shape in 33702118699, 33713287866, 33714777607, 33720758000, 33730276201: the install begins, the seed adopts 15/15 prebuilt assemblies, the compile-state mirror's satellite writes fail, and then the process emits nothing at all until the gate's own 600 s bound fires. The passing control did the identical work in 111 s.

The write wedge is a co-symptom, not the cause

Run 33730276201 failed exactly this way with ZERO VERDICT_TIMEOUT and zero OwnerUnreachable. The _Activity/compile-state write failures that #2543 quotes are CompileStateMirror background writes β€” caught, logged, retried on the next change β€” and they are neither necessary nor sufficient for the gate to fail. Chasing the 31 s write verdict is chasing a sibling of the real thing.

Where the silence starts β€” measured

1. The requesting hub is idle. CompileStateMirror's own diagnostic in run 33730276201:

[CompileStateMirror] Hosting/FleetConsole: satellite write failed …
System.TimeoutException: No response received in hub Hosting/FleetConsole within 00:01:00
for request CreateOrUpdateNodeRequest (id=lO-4g1N-Fkye6JnS6vzjAQ)
  β†’ target portal/nodeops-Q-40lJF-CEWErGWdWTeelQ.
This hub: RunLevel=Started Queue(buffer=0,deferred=0,openGates=0,deliveryActionCompleted=True).
This hub was idle while waiting, so it processed everything delivered to it and the silence is
upstream of here.

Started, empty queue, no open gates. The per-node owner is not wedged β€” it is waiting.

2. The delivery is sitting in nodeops' inbox, never executed. From the request-fate trail of a stale callback in the same run:

… β†’ RECEIVED runLevel=Started@portal/nodeops-Q-40lJF-CEWErGWdWTeelQ(+2ms)
  β†’ ENQUEUED@portal/nodeops-Q-40lJF-CEWErGWdWTeelQ(+2ms)
β‡’ the delivery reached a hub but no handler was ever entered β€” it is still being routed,
  or it was accepted and never executed.

ENQUEUED at +2 ms, and 33 seconds later still no HANDLER_ENTER. Note there is no DEFERRED stage β€” the message is not parked behind an init gate, it is in the buffer of an action block that is not advancing.

3. nodeops' queue latency, measured across the failing runs. Every state=Submitted@portal/nodeops(+Nms) in the request trails, bucketed:

≀ 3 171 ms   (36 deliveries β€” normal)
33 374 ms Β· 39 454 Β· 39 808 Β· 40 725 Β· 43 522 Β· 44 192 Β· 47 791 Β· 49 344 ms   (22 deliveries)

Nothing between 3.2 s and 33 s. That is not a slow hub; it is a hub that stops and restarts.

4. Who reports it. Stale callbacks in the failing runs are almost entirely the Hosting/* NodeType hubs β€” 13 FleetConsole, 11 InstanceRequest, 7 InstanceAction, 6 each Issue / DeploymentStatus / Admin, … β€” every one of them a CreateOrUpdateNodeRequest addressed to portal/nodeops. The passing control has three, all from one unrelated package. They do not stop answering independently; they queue behind one hub.

Why this presents as "many unrelated owners at once"

portal/nodeops-{meshId} is documented in MeshExtensions.cs as "The mesh's ONE dedicated node-CRUD execution hub", and it is additionally the router's designated carrier (RouterCarrier). So Store/*, Edu/* and Hosting/* failing to ack inside the same 30-second window is not a coincidence to be explained β€” it is one hub, seen from eight places.

The actor loop awaits the delivery's whole rule chain, not just the handler (MessageHub.HandleMessageAsync composes the rules with SelectMany and the actor-loop edge subscribes). A rule that goes async holds the block for its full duration. #2543 captured this directly on 2026-08-28:

Reader: Hub portal/nodeops-… RunLevel=Started Queue(buffer=45,deferred=0,exec=0)
  Executing(CreateNodeRequest, 24888ms)
  PendingCallbacks=26[ GetDataRequest@Store/Core, @Store/Install, … ]

One delivery occupying the block for 25 s, 45 queued behind it. That is the mechanism; which rule spends the 25 s has not yet been measured and is the next thing to find (see Open below).

🚨 It is not a recent regression β€” do not bisect

Measured over core's CD workflow, counting only runs where the bake/seal job reached a terminal conclusion:

period success failure N rate
2026-08-29 β†’ 09-02 76 31 107 29 %
2026-09-03 (to 08:37Z) 3 8 11 73 %

and the "before" period is not stationary β€” 2026-09-01 alone was 16/19 = 84 %, higher than today. All 39 failures are on the same step. A bisection against recent plugin merges cannot separate this signal from its own day-to-day variance; the job itself is only ~4 days old (it first appears in main-cd.yml at 3a5dfe45, 2026-08-29T21:13Z), so no longer baseline exists.

Bounds that make the symptom unreadable

Downstream of the saturation, four owner-side seams turn "the shared hub is busy" into "the owner produced no terminal". Each is a real defect in its own right; none of them is the cause.

  1. The generic patch path has no bound at all. DataExtensions.ApplyJsonMergePatchAndUpdate opens with stream.Take(1).WhenCompletesEmpty(…).Subscribe(onNext, onError) and no .Timeout(...). Rx's fourth outcome β€” never emits, never completes β€” is uncovered, and the only bounded watcher on that path (postSub) is created inside onNext, so it is never armed. A MeshNode patch reaches this path whenever GetDataSourceForType(typeof(MeshNode))?.GetStreamForPartition(null) is null.

  2. deferSub has no completion arm. In ApplyMeshNodePatchInTurn the cold-store re-arm is primary.Where(…).Take(1).Timeout(10s).Subscribe(_ => RunMergeTurn(true), _ => AckOnce(…)). If the primary store completes inside the bound, Take(1) completes, the Timeout is cancelled by that completion, neither arm runs, and the merge turn already returned null.

  3. AckOnce latches the once-only gate BEFORE the post and discards the post's result. When the post is refused (POST_REFUSED_SHUTTING_DOWN), the gate is already claimed, so RegisterOwnerDisposingNack's tryClaimAck() returns false and the ILatePatchVerdictSink.Dispatch route β€” the one that reaches an armed waiter with no message routed β€” is skipped. Every AckOnce call site is exposed; only the stand-aside case is guarded.

  4. The ownerIsShuttingDown() stand-aside is unbounded, and its safety argument cites a cap that was deleted. ArmPatchAckWatcher deliberately posts nothing when hub.IsShuttingDown, deferring to the ShutDown-phase disposal NACK. IsShuttingDown is disposalStarted || hostedHubs.IsCreationFrozen, and IsCreationFrozen flips on an ancestor's CloseCreation() cascade β€” "potentially seconds" before this hub's own DisposeRequest. LatePatchWriteWatch justifies its 30 s window as dominating "the disposal NACK after the owner's phased teardown (hosted-hub drain capped at 5 s)" β€” but that cap was removed in #1317: HostedHubsCollection.DisposeHubsReactive now reads "No Timeout β€” … the owning hub's disposal watchdog is the single backstop", and that watchdog is a stall detector re-armed on every subtree RunLevel transition, not a duration.

    Past 30 s the late verdict is not merely late: LatePatchResponseRegistry.Dispatch removes the entry before checking expiry and returns false without re-adding, so it is discarded in silence β€” which is why a failing run can carry VERDICT_TIMEOUT with zero LATE_NACK_TERMINAL.

There is a fifth, arithmetic one. LatePatchWriteWatch enumerates the owner-side paths as alternatives and takes their MAX (20 s) as the thing its 30 s must dominate. In ApplyMeshNodePatchInTurn they compose additively β€” cold-store defer (10 s) β†’ identity-gated echo (20 s) β†’ durable flush (10 s) β€” and the owner's clock starts at HANDLER ENTRY while the caller's starts at POST. With nodeops queue latency measured at 33–49 s, the interval between those two instants is larger than the entire margin. See Bounds Must Be Ordered.

How to read a failing seal in 60 seconds

  1. gh api "repos/Systemorph/MeshWeaver/actions/jobs/<id>/logs", then strip ANSI. The Actions log echoes the script source with a [36;1m prefix β€” those lines are the SCRIPT, not output.
  2. grep "GATE FAILED" β€” if it says install: <Package>, the gate died on PluginGateRunner's 600 s InstallTimeout, not on a write verdict.
  3. grep -o "state=Submitted@portal/nodeops[^)]*)" β€” bucket the +Nms values. A bimodal distribution with a tail past 30 s is this defect.
  4. grep "This hub was idle while waiting" β€” if the requester was idle, the silence is at the target, and the target named after β†’ target is the hub to investigate.
  5. Signature counts (STALE-CALLBACK, ADVANCE_WITHOUT_HANDOFF) are amplitude, not identity β€” they are present in passing runs too. The fate trail discriminates; the counts do not.

Open β€” what the next measurement must be

Which rule holds nodeops' action block? The 25 s Executing(CreateNodeRequest, …) capture is from 2026-08-28 and has not been reproduced since; today's job logs carry no hub-reader dump. Until that is measured, the saturation's cause is named but not identified. Two candidate shapes, both consistent with the actor loop awaiting the full rule chain:

Do not raise InstallTimeout, LateResponseWatchBound or QueueAdvanceBound to make the gate pass. Every one of those bounds is already reporting the truth: the shared hub is not draining.

🚨 One confound has been removed β€” read PendingCallbacks differently from now on

The 2026-08-28 capture reads PendingCallbacks=26[ GetDataRequest@Store/Core, @Store/Install, … ] alongside Executing(CreateNodeRequest, 24888ms). Those 26 were not issued by anything running on nodeops: they are one-shot GetMeshNode reads from mesh-singleton services that hold the DI root hub (the plugin catalog's boot services, the credential resolvers, the content route), and NodeOperationIssuingHub() hopped every one of them onto this hub because it was the only off-router hub there was. They then sat in the same block that could not dispatch them.

They now register on portal/reads-{meshId} instead β€” a hub with no handlers at all β€” via MeshExtensions.ReadIssuingHub(). See The /api/content 503 for why, and for the deterministic repro of the read side. Two consequences for the next measurement here:

🚨 2026-09-07 β€” the park is INSIDE the release wave, and it is not an unanswered node op (#3510)

Six seals were lost to this failure between 2026-09-06 23:36Z and 2026-09-07 06:09Z β€” CD 7950, 7959, 7967, 7968, 7976 failed while 7955, 7962, 7964, 7969, 7974, 7977, 7981 sealed. Roughly one started run in two, Hosting every time, always install: TimeoutException. The reading below is from CD 7976 (19b077868, bake job 101634597130).

What the sixth occurrence measured

05:44:31.5  ── Hosting: installing 145 file(s)…
05:45:28.8  Installed node-repo plugin Hosting: 144 written, 0 unchanged
05:45:56.7  Install: Hosting: adopted 15 prebuilt assembly(ies) for 15 installed type(s)
05:45:56.7  [PackageInstaller] recycling root Hosting …            ← by design; it SUCCEEDS
05:45:59.6  InitializeHubRequest | Hub: Hosting                     ← the root is back, 2.9 s later
05:46:04.5  [UpdateQueue] ADVANCE_WITHOUT_HANDOFF path=Hosting/Admin … /Backup … /LogEntry
05:46:34.9  (last log line of any kind)
                                     β‹― EIGHT MINUTES OF COMPLETE SILENCE β‹―
05:54:31.5  ── Hosting.Instance: installing 3 file(s)…              ← exactly T+600 s

Nothing was pending. [STALE-CALLBACK] reports every pending callback older than 30 s, every 5 s; it fired four times for HomeAssistant minutes earlier in this very run and zero times during the eight-minute park. So the install was not waiting on a message at all β€” not on an unanswered CreateOrUpdateNodeRequest, which is what #3510 was originally attributed to. It was parked on an observable that never terminated.

The control is in the same log. Edu β€” same shape, same run β€” printed [PackageInstaller] warmed installed root Edu 2.5 s after its own deferred release wave. warmed installed root Hosting never printed. WarmInstalledRoots runs immediately after RequestReleases(deferredWave), so the park is inside the wave.

Why the wave, by elimination from code

Every other composition between the deferred wave and the warm carries its own bound: AffectedNodeTypes (TypeEnumerationBudget, plus a Catch), SeedPrebuiltAssemblies (SeedBound), and the trigger write itself (BaseStateWaitBound 30 s, then verdict windows of LateResponseWatchBound + VerdictBoundGrace = 31 s across MaxConflictRetries, β‰ˆ124 s worst case). PackageInstaller.RequestReleases' nodeTypePaths.Select(ObserveNodeTypeRelease).Merge().ToList() carried none β€” which MeshNodeStreamHandle.BaseStateSource's remarks had already named in advance: "no per-leg bound and no outer bound β€” so ONE non-terminating leg parks the entire package install, silently, until the gate's own 600 s InstallTimeout reports install: TimeoutException against a package that installed fine 8 minutes earlier."

The fix, and what it is NOT

ObserveNodeTypeRelease states its own contract in its remarks and in its closing DefaultIfEmpty(false): exactly one emission, always. That covered three of Rx's four outcomes. The fourth β€” a source that neither emits nor faults nor completes β€” reached no handler, and neither DefaultIfEmpty nor Catch can see it. NodeTypeReleaseExtensions.BoundReleaseLeg now closes it: Take(1) (so the deadline is TOTAL, not Rx's inter-emission one) then ReleaseRequestBound, whose elapse answers false, logs, and names the NodeType.

🚨 No bound was raised and nothing is retried. ReleaseRequestBound is 180 s: strictly above the β‰ˆ124 s a legitimate trigger write can compose, and far below the installer's 600 s β€” the ordering Bounds Must Be Ordered requires, so it can only fire on a leg that is genuinely non-terminating and never on one that is merely slow. The outer 600 s bound knows only which PACKAGE did not finish; this one knows which TYPE never answered.

It does not claim to explain why a leg stops answering. It converts an eight-minute silent park into a named warning and lets the install finish, which is what makes the next occurrence one grep instead of a full bake-log read β€” the same role #3512's recycle line plays. Pinned by ReleaseWaveLegIsTotalTest (pure composition, TestScheduler, no mesh).

What this retires

The #3510 reading in Write Verdict Totality β€” "the upsert lane's CREATE leg has no disposal NACK" β€” is a real totality gap and is worth closing on its own merits, but it is not what fails these seals: 7976's one stale callback took the UPDATE leg (UPSERT_READ existing β†’ update), resolved inside 35 s, and the park that killed the run had no pending callback at all.

Reconnecting…
The server was updated. Reloading the page to pick up the latest version.