Skip to content

[Duplicate of #1122] sync hub BuildupAction hangs past the 120s startup bound, leaving the hub in FAILED state #2886

Closed as not planned

Description

@meshweaver-cloud

What is failing

A message hub under the sync/ partition failed initialization: one of its BuildupActions (observables registered via WithInitialization(...)) never emitted within the 120s startup budget, so MessageHub.HandleInitialize's liveness bound fired and put the hub in FAILED state, where it refuses every non-lifecycle request with a typed DeliveryFailure until it is recycled.

Probable cause

The timeout itself is the designed liveness guarantee (Hub Initialization Failure) — it makes the failure observable instead of wedging on the 30s per-message deferral. The defect is therefore the hung BuildupAction: the sync hub's buildup was waiting on a dependency that never completed. Cause of the hang: unclear; evidence points at a stalled downstream dependency rather than the hub's own init code. The failing pod logged an Orleans memory-stream dequeue timeout roughly half a minute earlier and NodeType recompile-release failures earlier the same night, consistent with a briefly stalled cluster (cross-silo stream/persistence) that the hub's buildup was blocked on.

Impact

Single occurrence on a single pod. A FAILED hub is recoverable by design (the Initialize gate opens anyway, disposal and lifecycle traffic still work), so this is a nuisance-level event, not an outage — but a hub left in FAILED state serves nothing until recycled, and a repeat under real traffic would take a sync hub dark.

Where to look

  • MessageHub.HandleInitialize (the .Timeout(...) / .Catch(...) composition) — the log line confirms this path worked as specified; do not raise the 120s bound.
  • The sync/ hub's BuildupActions: identify which dependency the sync hub waits on during buildup and why it did not complete within the budget. Per the architecture page, the fix belongs in that dependency, not in the timeout.
  • Related but not a duplicate: issue MessageHubGrain activation frequently times out during initialization due to unresolvable mesh nodes #1186 (MessageHubGrain activation timeouts, fingerprint 2f3d84b7e9b23752) — different component and symptom, same reliability family (hub initialisation stalling on unresolved dependencies).

Evidence

Fingerprint 50fd8fe63ba4b03a
Category MeshWeaver.Messaging.MessageHub
Severity Error
Exception System.TimeoutException
Namespace memex-cloud
Pods memex-portal-deployment-9bf79b774-tk88b
Occurrences 1
First seen 2026-08-31 05:55:47Z
Last seen 2026-08-31 05:55:47Z
Recent log lines
2026-08-31 05:55:47Z memex-portal-deployment-9bf79b774-tk88b fail: MeshWeaver.Messaging.MessageHub[0]
      Hub sync/G10n900HH0CvvLO4X8YpoA initialization failed — a BuildupAction did not complete within 120s (a hung dependency or stuck compile). Hub is now in FAILED state.
      System.TimeoutException: The operation has timed out.

Opened automatically from Admin/_LogIncident/50fd8fe63ba4b03a. Recurrences are folded into this issue rather than opening new ones.

Activity

  1. rbuergi commented on Aug 31, 2026

    @rbuergi
    Contributor

    Same incident as #2885 — one pod exhausting memory, filed four times

    All four reports share a pod, a namespace and a five-minute window, each with Occurrences: 1:

    pod memex-portal-deployment-9bf79b774-tk88b   ns memex-cloud
    
    05:52:32  #2885  OutOfMemoryException  routing a delivery to import/{guid}   (JSON WRITE)
    05:55:23  #2884  OutOfMemoryException  deserializing an inbound message      (JSON READ)
    05:55:47  #2886  TimeoutException      sync hub BuildupAction past its 120 s startup bound
    05:57:01  #2887  TimeoutException      recompile-set derivation abandoned
    

    One pod ran out of memory. The OOM surfaced first on the write path, then on the read path three minutes later; the two timeouts follow because a thrashing pod misses every bound it is held to.

    🚨 The two TimeoutExceptions are consequences, not defects. A sync hub that cannot complete BuildupAction inside 120 s, and a recompile-set derivation that gives up, are what a memory-starved process looks like from the inside — nothing is wrong with either bound. Filed separately they send four people into four subsystems (Orleans messaging, serialization, hub startup, the recompile lane) for one event, and each would find its own code behaving correctly.

    Consolidating into #2885 — chronologically first, and the closest to the root condition — where the actual question belongs: what allocated enough to exhaust the pod? Both OOM sites are Utf8JsonWriter.TranscodeAndWriteRawValue / JsonReaderHelper.TranscodeHelper, i.e. a single oversized JSON token, and both name the import path. An oversized import payload is the hypothesis worth testing first.

    (Filer note: fingerprinting by exception site is right for dedup but blind to correlation. Four reports from one pod inside five minutes, each Occurrences: 1, is a signal in itself — the same pod+window grouping that makes this obvious to a reader could suppress the follow-on reports automatically.)

  2. systemorph-com commented on Sep 15, 2026

    @systemorph-com
    Contributor

    Reopened — this fault is happening again.

    Still occurring: 342 more since the last update (343 total).

    • Last seen: 2026-09-15 18:57:57Z
    • Pods: memex-portal-deployment-9bf79b774-tk88b, memex-portal-deployment-9bf79b774-jwrng, memex-portal-deployment-7fd9668b69-jwzzl
    Recent log lines
    2026-08-31 15:40:38Z memex-portal-deployment-9bf79b774-jwrng fail: MeshWeaver.Messaging.MessageHub[0]
          Hub sync/YrH13aaDlkOQSWpt40ZgDg initialization failed — a BuildupAction did not complete within 120s (a hung dependency or stuck compile). Hub is now in FAILED state.
          System.TimeoutException: The operation has timed out.
    2026-08-31 15:40:38Z memex-portal-deployment-9bf79b774-jwrng fail: MeshWeaver.Messaging.MessageHub[0]
          Hub sync/fhf2DG0fSUqH8wPkSTx2fQ initialization failed — a BuildupAction did not complete within 120s (a hung dependency or stuck compile). Hub is now in FAILED state.
          System.TimeoutException: The operation has timed out.
    2026-09-15 18:57:57Z memex-portal-deployment-7fd9668b69-jwzzl fail: MeshWeaver.Messaging.MessageHub[0]
          Hub sync/nWA0zwEW_UGHA9HUq5hKEw initialization failed — a BuildupAction did not complete within 120s (a hung dependency or stuck compile). Hub is now in FAILED state.
          System.TimeoutException: The operation has timed out.
    
  3. rbuergi commented on Sep 15, 2026

    @rbuergi
    Contributor

    Closing as a duplicate of #1122 — this is the same failure, logged one level up.

    This issue's own body names the mechanism as "a hung BuildupAction … waiting on a dependency that never completed" and says the fix belongs in that dependency. The dependency has a name, and it has its own issue.

    The two log sites fire on the same event, milliseconds apart

    From the incident records on the control instance — this one (50fd8fe63ba4b03a, 343 occurrences) and #1122's (3d5effb62db3fe50, 217 occurrences):

    this issue (MessageHub) #1122 (DataContext)
    newest 2026-09-15 18:57:57.080Z 7fd9668b69-jwzzl 2026-09-15 18:57:57.085Z 7fd9668b69-jwzzl
    08-31 wave 15:40:20.735 ×4, 15:40:32.908 ×2, 15:40:38.791/.796/.796 15:40:20.735/.736 ×4, 15:40:32.933/.934, 15:40:38.792/.800/.805

    Same pod, same instants, interleaved to the millisecond. MessageHub.HandleInitialize's 120 s liveness bound and DataContext's 120 s initialization bound are expiring on one stalled initialisation: the sync hub's BuildupAction is the DataContext init, so when that never completes both bounds fire and both log. Two fingerprints, one fault.

    Where the work actually is

    #1122 is the site that names what failed to initialise rather than which hub was waiting — its newest sample is sglauser/_Answers/AgenticBusiness/01-MeetYourCoworker/Quiz, a per-node hub for a course answer sheet, with the message's own hint "likely a stuck NodeType compile, or a data source that never initialised." That is also the root of #3517's surviving occurrence (same node path, same pod, five minutes earlier), which I have closed onto #1122 as well.

    Nothing here argues for touching the 120 s bound, and this issue already says so — it is the liveness guarantee working, not the defect.

    Tracking on #1122: #1122 (comment)

    Closed 2026-09-15 by Claude Opus 5.

  4. systemorph-com commented on Sep 22, 2026

    @systemorph-com
    Contributor

    Reopened — this fault is happening again.

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

    • Last seen: 2026-09-21 17:06:24Z
    • Pods: memex-portal-deployment-7fc5f4874b-9zwrg, memex-portal-deployment-9bf79b774-tk88b, memex-portal-deployment-9bf79b774-jwrng, memex-portal-deployment-7fd9668b69-jwzzl
    Recent log lines
    2026-08-31 15:40:38Z memex-portal-deployment-9bf79b774-jwrng fail: MeshWeaver.Messaging.MessageHub[0]
          Hub sync/fhf2DG0fSUqH8wPkSTx2fQ initialization failed — a BuildupAction did not complete within 120s (a hung dependency or stuck compile). Hub is now in FAILED state.
          System.TimeoutException: The operation has timed out.
    2026-09-15 18:57:57Z memex-portal-deployment-7fd9668b69-jwzzl fail: MeshWeaver.Messaging.MessageHub[0]
          Hub sync/nWA0zwEW_UGHA9HUq5hKEw initialization failed — a BuildupAction did not complete within 120s (a hung dependency or stuck compile). Hub is now in FAILED state.
          System.TimeoutException: The operation has timed out.
    2026-09-21 17:06:24Z memex-portal-deployment-7fc5f4874b-9zwrg fail: MeshWeaver.Messaging.MessageHub[0]
          Hub sync/xarjMCm2iUy2vosDjEkWlw initialization failed — a BuildupAction did not complete within 120s (a hung dependency or stuck compile). Hub is now in FAILED state.
          System.TimeoutException: The operation has timed out.
    

    Re-addressed by the current identity function: this incident inherited 50fd8fe63ba4b03a (Systemorph/MeshWeaver.Plugins#1796). Those nodes are superseded and will not fold, file or comment again.

  5. changed the title [-]sync hub BuildupAction hangs past the 120s startup bound, leaving the hub in FAILED state[/-] [+][Duplicate of #1122] sync hub BuildupAction hangs past the 120s startup bound, leaving the hub in FAILED state[/+] on Sep 22, 2026
  6. added
    duplicateThis issue or pull request already exists
    on Sep 22, 2026
  7. rbuergi commented on Sep 22, 2026

    @rbuergi
    Contributor

    Finding: the line this ticket rests on cannot name the hung dependency — by construction, not by chance — so "identify which dependency the sync hub waits on" is unanswerable from any occurrence of it until the instrument changes. Not raising the bound; the bound is not the defect.

    What a sync/{clientId} hub's BuildupActions are (SynchronizationStream.ConfigureSynchronizationHub on top of DataExtensions.AddData, in Concat order):

    1. BindHub — the SYNCHRONOUS overload; runs inside Build() before any turn, so it cannot be the 120 s hang.
    2. RegisterWorkspaceTypes — quick.
    3. StartDataSourcesAndOpenGate — the DataContext initialization: the data sources' initial loads and the type-source fan-out. This is the one that waits on something outside the hub.

    Two bounds of equal length nest, and the uninformative one always wins. MessageHub.HandleInitialize wraps Concat(actions).ToList() in .Timeout(StartupTimeout ?? DefaultInitializationTimeout) = 120 s (MessageHub.cs:365), started at InitializeHubRequest. DataContext.InitializationTimeout is also 120 s (DataContext.cs:144), started when action 3 is subscribed — milliseconds later. On a hang the outer fires first, its Timeout disposes the Concat, and that unsubscribes the inner bound before it can fire. The inner one is the one that prints DescribePendingInitialization() — "NAME what did not finish; never guess at it (#1122)": which data sources have not settled, which streams never produced a first frame, which type-source legs are outstanding. The outer one prints a BuildupAction did not complete within 120s (a hung dependency or stuck compile) — two candidates, neither measured, the exact sentence shape #1122 removed one level down.

    So every occurrence of this fingerprint carries no information about WHICH of the three actions hung, and the ticket's probable cause ("a stalled downstream dependency") is a guess the log cannot confirm or refute.

    The fix that follows is diagnostic, not a bound: the outer timeout should name the pending BuildupAction — the Concat knows its index, and the delegate's method name (StartDataSourcesAndOpenGate, RegisterWorkspaceTypes, …) is on the Func already — and, for action 3, surface the DataContext's own pending-initialization description rather than lose it. Then a recurrence says what waited on what, and the "stalled cluster" hypothesis on this ticket becomes checkable. I am opening a PR for that; until it is live, a recurrence here is not new evidence.

    What I did not establish: which action hung on sync/G10n900HH0CvvLO4X8YpoA on 2026-08-31 — the instrument cannot say, and the initialization path has since been reworked three times (#2444 scope-teardown classification, #4067/#4068 transient-fault retirement, #4261 gate ordering), so the pod's behaviour then is not the code's behaviour now. Single occurrence, self-limiting, recoverable by design per the ticket's own impact statement; no severity label has been assigned and I am not assigning one.

  8. rbuergi commented on Sep 22, 2026

    @rbuergi
    Contributor

    Correction to my comment above — the action list was wrong, and the nesting runs the other way.

    I listed AddData's BuildupActions; those belong to the OWNING hub, not to sync/{clientId}. The sync hub's async BuildupActions are exactly one: the lambda hub => Initialize(hub) in SynchronizationStream.ConfigureSynchronizationHub (its BindHub is the synchronous overload, outside the Concat). Initialize is GetInitialValueAsync — the fan-out over every type source, Aggregated, so one leg that neither emits nor completes holds every sibling; for a per-node hub that is one storage read with no wall-clock bound by design. All of this is already on Doc/Architecture/DataContextInitializationTimeout, which I should have read first.

    That page also answers "which dependency": the OWNER hub's DataContext time-box waits on this sub-hub and fires milliseconds after the sub-hub's generic line (5 ms apart in the #1122 event), and since #1122 it prints DescribePendingInitialization() — which source, which stream, which type-source leg. So for an occurrence of this fingerprint the diagnosis is in the sibling line under category MeshWeaver.Data.DataContext in the same window, not in this one. For 2026-08-31 05:55:47Z on memex-portal-deployment-9bf79b774-tk88b I do not have that line; whoever has a Logs window there can read it.

    What stands from the comment above: this sub-hub's own line names nothing, and a hub with several async actions (every AddData hub has two) cannot say which one hung. The PR names the pending action by position and delegate on this line; it does not touch any bound.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    duplicateThis issue or pull request already exists

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions