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.
The generic patch path has no bound at all.
DataExtensions.ApplyJsonMergePatchAndUpdateopens withstream.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 insideonNext, so it is never armed. A MeshNode patch reaches this path wheneverGetDataSourceForType(typeof(MeshNode))?.GetStreamForPartition(null)is null.deferSubhas no completion arm. InApplyMeshNodePatchInTurnthe cold-store re-arm isprimary.Where(β¦).Take(1).Timeout(10s).Subscribe(_ => RunMergeTurn(true), _ => AckOnce(β¦)). If the primary store completes inside the bound,Take(1)completes, theTimeoutis cancelled by that completion, neither arm runs, and the merge turn already returnednull.AckOncelatches 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, soRegisterOwnerDisposingNack'stryClaimAck()returns false and theILatePatchVerdictSink.Dispatchroute β the one that reaches an armed waiter with no message routed β is skipped. EveryAckOncecall site is exposed; only the stand-aside case is guarded.The
ownerIsShuttingDown()stand-aside is unbounded, and its safety argument cites a cap that was deleted.ArmPatchAckWatcherdeliberately posts nothing whenhub.IsShuttingDown, deferring to the ShutDown-phase disposal NACK.IsShuttingDownisdisposalStarted || hostedHubs.IsCreationFrozen, andIsCreationFrozenflips on an ancestor'sCloseCreation()cascade β "potentially seconds" before this hub's ownDisposeRequest.LatePatchWriteWatchjustifies 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.DisposeHubsReactivenow reads "No Timeout β β¦ the owning hub's disposal watchdog is the single backstop", and that watchdog is a stall detector re-armed on every subtreeRunLeveltransition, not a duration.Past 30 s the late verdict is not merely late:
LatePatchResponseRegistry.Dispatchremoves the entry before checking expiry and returnsfalsewithout re-adding, so it is discarded in silence β which is why a failing run can carryVERDICT_TIMEOUTwith zeroLATE_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
gh api "repos/Systemorph/MeshWeaver/actions/jobs/<id>/logs", then strip ANSI. The Actions log echoes the script source with a[36;1mprefix β those lines are the SCRIPT, not output.grep "GATE FAILED"β if it saysinstall: <Package>, the gate died onPluginGateRunner's 600 sInstallTimeout, not on a write verdict.grep -o "state=Submitted@portal/nodeops[^)]*)"β bucket the+Nmsvalues. A bimodal distribution with a tail past 30 s is this defect.grep "This hub was idle while waiting"β if the requester was idle, the silence is at the target, and the target named afterβ targetis the hub to investigate.- 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:
- a rule that performs IO per delivery (a storage read, a permission fold, a path resolution) and is therefore charged to the block rather than to the pool; or
- amplification β a delivery whose failure produces more deliveries on the same hub, the shape Action-Block Wedge Prevention exists to forbid.
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:
- A contributor is gone, not the cause. Those reads no longer add deliveries to this block, and no longer burn 10 s budgets that their callers retry β but nothing about the duration of a node-CRUD turn has changed. If the bimodal latency survives, that is the real answer.
PendingCallbacksonnodeopsis now attributable. A read still pending there was issued by something running on this hub, which is a much smaller set to search than "any mesh singleton in the process".
π¨ 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.
Related
- Action-Block Wedge Prevention β the invariants a single-threaded hub must satisfy so no input can saturate it.
- Bounds Must Be Ordered β why an inner bound just under an outer one destroys the outer one's diagnosis.
- Reading a Write Verdict β what each owner-side error code means and which ones are auto-retried.
- Reading CI Signals β why a skipped or absent required context reads as green.