Name the /api/content 503's third cause: the owning hub is still STARTING (#3931) by rbuergi · Pull Request #3936 · Systemorph/MeshWeaver

rbuergi · 2026-09-10T16:01:09Z

Root-causes #3931 and names a third cause of the /api/content ~10 s 503.

What is actually happening

The collection-config GetDataRequest is addressed at the owning node's own per-node hub. On the
first read of a node since the process started, that request is what creates the hub — and
MessageService parks every arriving delivery in the deferred queue until that hub's last
initialization gate opens. So the read never measured the owner's health. It measures the owner's
start-up, and reports a node that is present, permitted and about to answer as unreachable.

The bounds are inverted, which is the ordering ReadBudget's own remarks forbid — "a bound
nested inside another bound must be able to fire FIRST":

Bound on the work the read triggers	Value
the reader's budget	10 s
deferred delivery, per message (`MessageService.cs:151`)	30 s
the hub's initialization turn (`MessageHub.cs:210`)	120 s
`DataContext` initialization (`DataContext.cs:144`)	120 s
monolith path resolution (`RoutingServiceBase.cs:306`)	30 s
Orleans first-node resolution (`MessageHubGrain.cs:88`)	30 s
NodeType slow path, no progress (`NodeTypeEnrichmentHelpers.cs:69`)	30 s

The 10 s always fires first, so no inner bound can ever deliver its diagnosis to this caller.

Production evidence, read-only, 2026-09-10

The probe's 15:02 run reads the same asset three times, 2 s apart:

15:02:28  round 1: platform=503  absent-control=404
15:02:40  round 2: platform=503  absent-control=404
15:02:43  round 3: platform=200  absent-control=404

Two budgets burned, then the same URL in 0.2 s ~24 s after the first attempt — a start-up that
completed on its own, inside every one of its own bounds and outside the reader's. Meanwhile five
previously-untouched owning nodes each served their first asset in 0.14–0.20 s once the replica
was quiet, so a cold start is normally ~100× inside the budget. The window follows
Doc/_Activity/import-bfcebef8e3a0b6ac — "Import Doc (1446 nodes)", 11 min earlier — and a
fleet-wide NodeType bake wave (compile-state stamped 15:04:58→15:05:23Z across two dozen
partitions).

🚨 Why two sessions eliminated the live cause

Cause C wears Cause A's signature exactly. The documented Queue(buffer=0,…) discriminator
snapshots the READER — portal/reads-{meshId}, a hub that registers no handlers — which under
Cause C is idle. Verbatim from the control run in this PR, against the pre-fix code, on a mesh where
the owning hub was in the same process and answered milliseconds later:

Reading content collection config from 'TestData/ColdProbe' gave up after 10s — the owning hub
never answered. … Reader: Hub portal/reads-… RunLevel=Started
Queue(buffer=0,deferred=0,drainsInFlight=0)
PendingCallbacks=1[…=GetDataRequest@TestData/ColdProbe(10002ms)]
Target: NO LOCAL HUB at 'TestData/ColdProbe' — it never activated in this process …

Two things in that line were wrong, and both are fixed:

"the owning hub never answered" is a claim a budget cannot support. It now states only that no
answer reached the reader within the budget.
Target: NO LOCAL HUB was a CONSTANT, not evidence. GetHostedHub searches ONE hub's own
collection — neither the hosted tree nor the parent chain — and every per-node hub is hosted by
the mesh hub, while the reader on this seam hosts nothing. So it printed that verdict for
every read alike. It now probes the mesh hub and, when the owner has not reached
RunLevel=Started, says Target: STILL STARTING — … in words.

Doc/Architecture/PodHubClaimReassertion quoted that clause as evidence in its own chain; the row is
annotated (its verdict rests on rows 3 and 5, which are independent of it).

The repro, and the controls both ways

ContentReadPaysTheOwningHubsStartupTest (test/MeshWeaver.Graph.Test) — monolith mesh, no sleeps,
no timers, no cluster. One node's reactive initialization is parked on an AsyncSubject the test
completes, matched by address, so the owning hub is genuinely mid-start.

RED without the fix — measured by reverting ReadBudget.cs and re-running:
Expected "…the owning hub never answered… Target: NO LOCAL HUB at 'TestData/ColdProbe'…" to contain "STILL STARTING". 1 failed, 2 passed — so the harness was not failing everything.
GREEN with it — 3/3, and 6/6 together with ContentReadIsNotQueuedBehindNodeCrudTest.
Positive control: a node whose hub starts normally resolves the same reference.
Control the other way: an unresolvable path still answers NotFound inside TestTimeouts.Quick
— it returns at path resolution and never reaches the bounded read, which is the present/absent
discrimination the prod probe asserts.
The parked read resolves the moment the gate opens, which is what makes the 503 a false
negative rather than a measurement.

What this deliberately does NOT do

No bound moved and no behaviour changed. Widening ReadBudget.Default, retrying inside the route and
pre-warming every node are all forbidden, and the measurement says the read is not stuck — the
owner starts and answers. The three exits that remain are recorded on the page as an open
decision: wait for the start-up (a bound change), answer without the owning hub (the cache the CQRS
page refuses), or keep interactive traffic off a replica whose boot bake has not settled (readiness —
the only one that removes the user-visible symptom, at the cost of rollout time).

Also recorded: on memex.meshweaver.cloud search 'nodeType:Hosting/LogEntry' carries no
content-route lines at all, so the log-based discriminators are unreachable through the sanctioned
API. The page therefore gains a black-box discriminator that needs only curl.

Probe message

The probe's failure message always printed BOTH counters, so a healthy negative control read as
"the impossible path failed to answer 404 in 0/3 samples" — the sentence #3931 was filed on, and a
whole hypothesis lost to it. It now names only the branch that fired.

Verification

dotnet build … -c Release -warnaserror — 0 Error(s) on MeshWeaver.Mesh.Contract,
MeshWeaver.Graph.Test, MeshWeaver.Layout.Test, MeshWeaver.Documentation.Test.
MeshWeaver.Graph.Test content-route tests: 6/6.
ReadBudgetTest: 14/14.
MeshWeaver.Documentation.Test (incl. DocumentationLinkIntegrityTest, WhatsNewEntryIntegrityTest):
368/368.

Pairs-with: none — no public type or member is removed; ReadBudget and HubUnreachableException
keep their exact public surface.

🤖 Generated with Claude Code

https://claude.ai/code/session_01S25PJZbVeCbkWhCfMub9P7

…TING (#3931) A cold `/api/content` read 503s at ~10.2 s and the same URL then serves in 0.2 s. Neither documented cause fits: Cause B's cure is deployed, and Cause A cannot explain a per-node failure that heals per node. What is actually happening is that the `GetDataRequest` for the collection config is the first thing to address that node since the process started, so it is what CREATES the owning hub — and `MessageService` parks every delivery in the deferred queue until that hub's last initialization gate opens. The read therefore measures the owner's START-UP, not its health. Every bound on that start-up is LARGER than the 10 s budget waiting on it (deferral 30 s, hub init 120 s, DataContext init 120 s, routing resolution 30 s, first-node resolution 30 s, NodeType slow path 30 s), so the reader's bound always fires first and no inner bound can ever deliver its diagnosis — the ordering `ReadBudget`'s own remarks forbid. Measured on memex.meshweaver.cloud 2026-09-10: the probe's 15:02 run read the same asset three times — 503, 503, then 200 in 0.2 s, about 24 s after the first attempt — while five previously-untouched owning nodes each served their first asset in 0.14-0.20 s once the replica was quiet. The window follows an "Import Doc (1446 nodes)" activity and a fleet-wide NodeType bake wave. Two things in the diagnostic were wrong and are fixed here: * The headline asserted "the owning hub never answered", which a budget cannot know and which was false in the shape that actually occurs. It now states only that no answer reached the reader within the budget. * `Target: NO LOCAL HUB` was a CONSTANT, not evidence. `GetHostedHub` searches one hub's own collection and every per-node hub is hosted by the MESH hub, while the reader on these seams is `portal/reads-{meshId}`, which hosts nothing — so it printed that verdict for every read alike. It now probes the mesh hub, and when the owner is present but has not reached `RunLevel=Started` it says so in words. That matters because Cause C wears Cause A's signature exactly: the documented `Queue(buffer=0,…)` discriminator snapshots the READER, which under Cause C is idle. The control run in this change reproduces Cause A's documented line verbatim on a mesh where the owner was in the same process and answered milliseconds later. `ContentReadPaysTheOwningHubsStartupTest` is the deterministic repro: one node's reactive initialization is parked on a subject the test completes, so the owning hub is genuinely mid-start with no sleep and no timer. Controls both ways — a node whose hub starts normally resolves, an unresolvable path still answers NotFound without paying the budget, and the parked read resolves the moment the gate opens, which is what makes the 503 a false negative rather than a measurement. No behaviour and no bound changed: widening `ReadBudget.Default`, retrying in the route and pre-warming are all forbidden, and the measurement says the read is not stuck. The three exits that remain are recorded on the page as an open decision. Also corrects the prod probe's failure message, which always printed BOTH counters and so reported a healthy negative control as "the impossible path failed to answer 404 in 0/3 samples" — the sentence #3931 was filed on, and a whole hypothesis lost to it. It now names only the branch that fired. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01S25PJZbVeCbkWhCfMub9P7

A failing assertion between the read and the release would strand the parked hub mid-initialization, where it holds its gate until the 120 s buildup timeout and teardown waits behind it. Same discipline as ContentReadIsNotQueuedBehindNodeCrudTest. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01S25PJZbVeCbkWhCfMub9P7

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01S25PJZbVeCbkWhCfMub9P7

Copilot

🟡 Changes recommended

Unresolved findings affect test cleanup, timeout diagnostic accuracy, probe-result reporting, and documentation consistency.

Once you've addressed the issues Copilot identified, you can request another Copilot review.

Pull request overview

Improves /api/content timeout diagnostics when the owning hub is still starting, with regression tests and documentation updates.

Changes:

Reports target startup state without overstating timeout causes.
Adds cold-start and control-path coverage.
Updates probe messaging and architecture documentation.

File summaries

File	Summary
`test/MeshWeaver.Graph.Test/ContentReadPaysTheOwningHubsStartupTest.cs`	Adds cold-start regression and control tests.
`src/MeshWeaver.Mesh.Contract/ReadBudget.cs`	Adds target-aware timeout diagnostics.
`src/MeshWeaver.Documentation/Data/WhatsNew/2026-09-10-a-read-that-timed-out-no-longer-blames-the-hub-it-was-waiting-for.md`	Documents the diagnostic change.
`src/MeshWeaver.Documentation/Data/Architecture/PodHubClaimReassertion.md`	Updates historical diagnostic evidence.
`src/MeshWeaver.Documentation/Data/Architecture/ContentRoute503.md`	Documents the third failure cause and discriminators.
`.github/workflows/prod-synthetic-probe.yml`	Refines synthetic probe failure reporting.

Review details

Suppressed comments (7)

.github/workflows/prod-synthetic-probe.yml:152

This branch is reachable with neg_wrong == 1 (the route-failure threshold is >= 2), but the message says the impossible path “correctly 404s” and that “the route works.” That overstates the evidence and can misclassify a partially failing control; include the actual 3 - neg_wrong count and either qualify the route verdict or require a fully healthy control before declaring the asset missing.

          if [ "$pos_absent" -ge 2 ]; then
            echo "::error::${PORTAL} does not serve the platform content asset $pos ($pos_absent/3 samples 404)," \
                 "while the impossible path correctly 404s — so the route works and this asset is missing." \
                 "It ships in the portal image (MeshWeaver.Documentation EmbeddedResource, Doc/* content" \
                 "collection, isStatic), so a 404 here means the Doc partition did not land on this deployment."

src/MeshWeaver.Documentation/Data/Architecture/ContentRoute503.md:315

The repro's bounded coldRead has already errored and been disposed before _release is signalled; the later Resolve is a new subscription. Thus “the identical read resolves the moment the gate opens” is not what this test demonstrates. Please describe this as a subsequent read of the same reference, or change the repro to keep a live subscription.

Until one is taken, what #3931 buys is that an occurrence is now **identifiable in one line** instead
of being misfiled as Cause A. The repro is `ContentReadPaysTheOwningHubsStartupTest`
(`test/MeshWeaver.Graph.Test`): one node's reactive initialization is parked on a subject the test
completes, the content read must say what it observed, and the identical read resolves the moment the
gate opens — which is what makes the 503 a false negative rather than a measurement.

src/MeshWeaver.Documentation/Data/Architecture/ContentRoute503.md:273

NO LOCAL HUB is not enough to conclude that the owner is absent from this process: activation can still be queued before HostedHubsCollection publishes the hub, and the route's 30 s resolution bound can outlive the reader's 10 s budget. This row should say that no hosted hub was observed (or expose activation state), otherwise an in-progress cold activation is still misclassified as a remote/absent owner.

Target: Hub <owner> RunLevel=Started Queue(buffer=0,deferred=0,…)
    ⇒ the owner was up: fall through to the reader clause and decide A vs B there.
Target: NO LOCAL HUB at '<owner>'
    ⇒ the owner is not in THIS process. Not decidable from this line — use the black-box table.

src/MeshWeaver.Documentation/Data/Architecture/ContentRoute503.md:2

Please update the architecture index in the same change. src/MeshWeaver.Documentation/Data/Architecture.md:308 still advertises this page as “two causes with opposite fixes” and “the one field,” which now contradicts the new three-cause/two-discriminator contract and sends readers to an obsolete model.

Name: The /api/content 503 — Three Causes, Two Discriminators

src/MeshWeaver.Documentation/Data/WhatsNew/2026-09-10-a-read-that-timed-out-no-longer-blames-the-hub-it-was-waiting-for.md:28

The initial bounded read cannot “still succeed” after its timer errors because that subscription is disposed; the test only shows that a subsequent request for the same URL succeeds after startup completes. Please avoid implying that one timed-out observable resumes later.

Nothing about the timing changed: the same read still succeeds the moment the node finishes
starting, and a genuinely unreachable node still fails the same way it always did. What is new is
that the two are no longer written the same.

src/MeshWeaver.Mesh.Contract/ReadBudget.cs:290

GetHostedHub(..., Never) only reads the published hub dictionary. While RoutingServiceBase is still resolving the path or constructing the hub, its activation serializer can hold the delivery for up to the 30 s routing bound before publication; the 10 s read budget can therefore reach this branch even though activation is in progress and will later create the hub. “It never activated” (and the implied lost reply) is not supported by this snapshot; report that no hosted hub was observed or include the activation-in-flight state, and align the discriminator docs.

        if (reader.GetMeshHub().GetHostedHub(new Address(target), HostedHubCreation.Never)
            is not { } owner)
            return $"Target: NO LOCAL HUB at '{target}' — it never activated in this process (or it "
                   + "is owned by another silo and the reply was lost in transit).";

test/MeshWeaver.Graph.Test/ContentReadPaysTheOwningHubsStartupTest.cs:173

coldRead has already terminated with HubUnreachableException; when the FailIfNoFirstEmission timer wins, it disposes the source. This ContentFileResolver.Resolve call is therefore a new subscription, so it cannot prove that the timed-out read later resolves after release as the test's comments claim. Either preserve and assert a live source separately, or change the test and related documentation to say that a subsequent read of the same reference succeeds.

            // mid-initialization holds its gate until the 120 s buildup timeout, and teardown would
            // wait behind it. Releasing it is also the half that makes the diagnosis above a FALSE
            // NEGATIVE rather than a measurement: nothing about the node changed, only its hub
            // finished starting.

Files reviewed: 7/7 changed files
Comments generated: 1
Review effort level: Lite

💡 Configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

+        await _parked.Should().Within(TestTimeouts.Convergence)
+            .Emit("the owning hub's start-up must actually be in flight, or this test proves nothing");
+
+        var notification = await coldRead;
+
+        notification.Exception.Should().BeOfType<HubUnreachableException>(
+            "a lapsed read budget is reported as a retryable HubUnreachableException, which "
+            + "BlazorHostingExtensions.ContentFailure maps to 503");
+        var message = notification.Exception!.Message;
+        message.Should().Contain(ColdNodePath,
+            "the diagnostic must name the address that did not answer");
+        message.Should().Contain("STILL STARTING",
+            "the owner exists in this process and has not reached RunLevel=Started — a read "
+            + "DEFERRED behind a start-up is not a lost reply, and saying 'the owning hub never "
+            + "answered' is what made two sessions eliminate the one live cause (#3931)");
+        message.Should().NotContain("NO LOCAL HUB",
+            "the target probe must ask the MESH hub, which hosts every per-node hub — probing the "
+            + "reader (portal/reads-{meshId}, which hosts nothing) answered this for every read "
+            + "alike, so the clause carried no information at all");
+
+        // 🚨 The half that makes the diagnosis a FALSE NEGATIVE rather than a measurement: nothing
+        // about the node changed, only its hub finished starting.
+        _release.OnNext(Unit.Default);
+        _release.OnCompleted();


github-actions · 2026-09-10T16:12:36Z