LiveQueryHandoffDropTest fails post-warmup-fix (e2080c4fa) — new information per #2338's own ask #2377

Activity

1. rbuergi

   added

   bugSomething isn't workingSomething isn't working

   on Aug 26, 2026
2. rbuergi commented on Aug 26, 2026

   

   rbuergi

   on Aug 26, 2026

   ContributorAuthor

   More actions

   Consolidating #2319 (which I reopened on the same run, minutes apart) into this ticket. Three findings from that analysis, carried over:

   1. The branch was not stale. fix/2342-ai-internalsvisibleto contains BOTH c4542d149 (the warm-up) and its review follow-up c65ba3936, and was 0 commits behind main. So this is the fixed code failing, not a re-sample of the pre-fix flake on an old branch.
   2. The failure is inside the warm-up itself — the phase that exists to absorb cold-JIT cost. It cannot be explained by the thing it was built to absorb.
   3. The 30 s budget is against an empty InMemoryStorageAdapter, and the empty-result path emits Initial unconditionally. JIT of an Rx pipeline does not take 30 s. So Initial was not slow — it did not arrive at all.

   What the earlier investigation established still stands: an instrumented 400-iteration in-process loop at DOTNET_PROCESSOR_COUNT=4 failed only ever on iteration 0. That is real and it is why the warm-up helped. But that loop was structurally blind to any cause that only manifests in a cold process or via cross-test state — it could only ever observe causes that reproduce in a warm process. So it never ruled this out.

   Unproven hypothesis, offered for someone to disprove rather than adopt: the Initial read is offloaded through IIoPool, and with no IoPoolRegistry in this test the provider falls back to IoPool.Unbounded (thread pool), with a further Scheduler.Default.Schedule hop at StorageAdapterMeshQueryProvider.cs:1440. MeshWeaver.Hosting.Test runs 232 tests in one process, and this class deliberately parks a thread in its gated scenario. Worth checking specifically: does that scenario release the parked thread and dispose its subscription on every exit path, including when an assertion fails? A leak there would poison whichever test runs next — and would look exactly like "too degraded to JIT".

   That the rerun reproduced it identically on the same runner is a useful signal: it points away from a random race and toward something about that process/runner state.

   🚨 Operational note: the fail-fast in c65ba3936 was correct (a silently-skipped warm-up lets the gated assertions run cold and misreport their own timeout as a dropped row), but it means a warm-up miss now fails the shard — so this test can red an unrelated PR, as it did to #2366 whose diff is two InternalsVisibleTo lines.

   An agent is on this now with instructions to reproduce the way CI runs it (whole assembly, one cold process, DOTNET_PROCESSOR_COUNT=4 — an isolated single-test run discriminates nothing), name the exact mechanism, and fix the root cause. Explicitly NOT to raise the timeout and NOT to weaken the fail-fast.
3. rbuergi commented on Aug 26, 2026

   

   rbuergi

   on Aug 26, 2026

   ContributorAuthor

   More actions

   Root-caused and fixed in #2389. It is a framework bug, and it reaches production.

   Reproduced first, then diagnosed

   The condition is cold process + whole assembly + a real 4-CPU budget. A Linux container at
   --cpus 4 with DOTNET_PROCESSOR_COUNT=4, running the whole MeshWeaver.Hosting.Test assembly
   cold: 3 failures in 13 runs (~23%). It never reproduced on this Mac even at
   DOTNET_PROCESSOR_COUNT=4, because that only sets a number — the container's cgroup quota makes
   threads genuinely contend.

   The runner was not degraded. From the failing shard's own trx: the test consumed exactly
   00:00:30.017 — its whole budget — while the other 231 tests took 6.8 s, against 5.8 s locally.
   And the two attempts on that run failed at positions 75 and 158, with different neighbours, so it
   was never adjacent-test pollution either.

   The mechanism

   Instrumenting the pipeline showed Subscribe returning having never walked — no error, no
   completion — and Initial still absent after a further 15 s. The chain stopped at
   walkPairs.ToObservable().

   The parameterless IEnumerable.ToObservable() defaults to SchedulerDefaults.Iteration =
   CurrentThreadScheduler, which does not mean "run it here now". It keeps a
   [ThreadStatic] bool for "a trampoline is already running on this thread"; while that is set,
   Schedule only enqueues, leaving the item for whoever owns the outer trampoline to drain.

   Capturing Environment.StackTrace at the point of failure gave the owner — 558 frames, bottom-up:

   MessageService.DrainOne()                 // the hub's own pump, on a ThreadPool thread
    -> Producer.SubscribeRaw
      -> CurrentThreadScheduler.Schedule     // trampoline OPENED here; the flag is now set
        -> ... ~500 Rx frames ...
          -> ToTaskObserver.OnCompleted -> TaskCompletionSource.TrySetResult   // a .ToTask() resolves
            -> AwaitTaskContinuation.RunOrScheduleAction(allowInlining: true)  // awaiter resumes INLINE
              -> ... xUnit's runner, then WarmUpJitAndTypeLoad ...
   

   A Task completed from inside an Rx pipeline resumes its awaiter inline, still inside the
   trampoline, and everything it then calls inherits the flag. Here the resumed awaiter was a mesh
   teardown, so xUnit carried on running tests on that stack. The warm-up subscribed there, its walk was
   enqueued rather than run, and it then blocked 30 s on warmInitial — which is the deadlock: the
   queue could not drain until the blocked frame returned, and it never would.

   This is not a test artefact. The trampoline's owner is the hub message pump. Any caller resumed
   from a .ToTask() inside a hub pipeline that subscribes a live query and waits is exposed — and the
   symptom in the portal is a live children listing (chat token chip, notification bell, folder view)
   that opens and silently stays empty forever while a point read returns the same content immediately.

   Correcting the two hypotheses on this ticket

   • IIoPool / IoPool.Unbounded is not involved. StorageAdapterMeshQueryProvider._ioPool is
     assigned in the constructor and never invoked — grep for _ioPool. in that file returns only
     comments. The Scheduler.Default.Schedule hop near line 1440 is on the backlog path, which runs
     only after Initial has been emitted. Neither is on the failing path.
   • The gated scenario does not leak its parked thread. Its finally sets ReleaseRead, joins and
     disposes on every exit path, and the warm-up runs before it in any case. Not the cause.
   • Thread-pool starvation is ruled out by measurement: at the moment of failure the pool showed
     threads=4 pending=0 avail=32766/1000. Nothing was starved — the work was never queued to the
     pool at all.

   What stands from #2338

   The 400-iteration warm-process finding is real (only ever iteration 0 failed) and
   WarmUpJitAndTypeLoad stays. It was incomplete, exactly as you said: a warm-process loop cannot
   observe a cause that only manifests cold or via cross-test state.

   The fix, proven both ways

   ToInlineObservable() (ImmediateScheduler — no ambient per-thread state; its recursive form is
   trampolined through a per-call AsyncLock, so long walks still iterate without growing the stack),
   applied to the scope walk and the IStorageAdapter read paths that make the same promise.

   LiveQueryForeignTrampolineTest is a deterministic repro — no container, no 4-CPU cap: it
   subscribes from inside a real trampoline and blocks there.

   check	result
   repro test without the fix	3 of 4 shapes FAIL, 15.1 s
   repro test with the fix	4 of 4 pass, 0.08 s
   whole assembly, cold, 4 CPUs — before	3 failures / 13 runs
   whole assembly, same conditions — after	0 failures / 40 runs

   No budget was widened and no fail-fast weakened.
4. rbuergi

   closed this as completedin #2389on Aug 26, 2026
5. rbuergi

   added 5 commits that reference this issue on Aug 26, 2026

   Merge pull request #2389 from Systemorph/fix/2377-live-query-foreign-…

   ...

   e39e221

   fix: no ToTask in the memex portal (#2751)

   ...

   e3dafd5

   test: no ToTask in the test tree either — 1,538 bridges become the de…

   ...

   57de73c

   fix(guard): the observable→Task bridge guard enforced a SPELLING — ma…

   ...

   3199350

   test(#3213): bridge every observable wait through .Await(), not Rx's …

   ...

   117a43b