Skip to content

Flake: AreaProbeTest's synthetic frames are queued onto ANOTHER test's CurrentThreadScheduler trampoline and never arrive — 35% on whole-assembly runs #1826

Closed

Description

@rbuergi

AreaProbeTest's two synthetic-frame tests fail ~1 in 3 whole-assembly runs — never in isolation, never under added CPU load alone. The two affected cases:

  • AreaProbeTest.MenuChromeFrame_ThenGreenTable_ReportsThePassSummary
  • AreaProbeTest.NotFoundFrame_ThenGreenTable_IsPassed

Part of the flake population in #1384.

Measured

macOS, 18 cores, Release build, MeshWeaver.PluginTester.Test run as the xUnit v3 in-process exe.

run shape iterations failures
single test method, no load 30 0
single test method, 64 CPU hogs 40 0
-class AreaProbeTest (whole class), no load 20 0
whole assembly, no load 20 7 (35 %)
whole assembly, instrumented re-runs 12 + 12 + 6 3 / 5 / 2

CPU load is not the trigger. Running the rest of the assembly is.

What actually fails

Instrumenting the test (stopwatch + a .Do() on the frame source + CurrentThreadScheduler.IsScheduleRequired at entry) gives a 12/12 perfect correlation:

NOTFOUND outcome=Passed || t0 scheduleRequired=True  | defer@19 | frame@35 | frame@37 | done@43
NOTFOUND outcome=Passed || t0 scheduleRequired=True  | defer@15 | frame@26 | frame@28 | done@34
NOTFOUND outcome=Failed || t0 scheduleRequired=False | defer@0  |                       done@5004
NOTFOUND outcome=Failed || t0 scheduleRequired=False | defer@0  |                       done@5003

scheduleRequired=True at test entry → pass. scheduleRequired=False → fail, at exactly 5000 ms, with zero frames ever delivered:

Tests area reported no verdict within 5s (expected a ✅/❌ table with an 'N/M passed' summary)

Note the detail line: lastTransient is null, i.e. not even the first (Area not found) frame arrived. The classification pipeline is a pure function and never ran at all — the timeout is the only thing that fired.

Mechanism

The tests drive the classification seam with

var frames = new[] { NotFound, GreenTable }.ToObservable();

IEnumerable<T>.ToObservable() defaults to SchedulerDefaults.Iteration = CurrentThreadScheduler, and its emit loop is scheduled as a separate work item. CurrentThreadScheduler.Schedule only runs a trampoline when none is installed on the calling thread; if one already is, it merely enqueues behind whatever that trampoline is doing.

Environment.StackTrace captured on the failing runs shows exactly who owns the trampoline — the test method is executing on the stack of another test's Rx completion:

AreaProbeTest.NotFoundFrame_ThenGreenTable_IsPassed()          ← our test, running here
  … 60 frames of Xunit.v3 runner …
  Task`1.TrySetResult / AwaitTaskContinuation.RunOrScheduleAction
PluginGateRunnerTest.CommercialPackage_InstallsAndGatesGreen()
PluginGateRunnerTest.RunGate(String repo)
  TaskCompletionSource`1.TrySetResult
  TaskObservableExtensions.ToTaskObserver`1.OnCompleted()       ← the ToTask() bridge completing…
  … Rx sink chain …
  ObservableImpl.ConcatMany`1.ConcatManyOuterObserver.Drain()   ← …inside PluginGateRunner's
                                                                  .ToObservable().Concat() trampoline

So the chain is:

  1. PluginGateRunner.RunPackages composes the per-package gate with .ToObservable().Concat().ToList() — the whole run therefore executes inside one CurrentThreadScheduler trampoline.
  2. PluginGateRunnerTest.RunGate bridges that to a Task with .FirstAsync().ToTask(…). When the gate completes, TrySetResult runs the awaiting continuation inline, on the trampoline thread, inside the trampoline.
  3. That continuation is the xUnit v3 runner, which proceeds to run the next test class synchronously on that same stack. AreaProbeTest now runs with a live, foreign trampoline installed.
  4. Its ToObservable() frames are queued onto that foreign trampoline's queue, which cannot drain until the entire inlined runner stack unwinds. Timeout(5s) wins.

This is why it is invisible in isolation and immune to CPU load: it is an ordering/inlining condition, not a timing one.

Verdict: a TEST defect, not a gate defect

Explicitly refuting the working hypothesis that this was cold-start cost landing inside the operator's 5 s budget:

  • The failing runs consume 0 ms of legitimate work — no frame is ever produced. Nothing is slow; something never runs.
  • AreaProbe.ClassifyTestsFrames and the whole classification path are deterministic and correct.
  • The product path (AreaProbe.ExecuteTestsArea → Frames() → GetRemoteStream<JsonElement, LayoutAreaReference>) never uses a CurrentThreadScheduler-scheduled source; frames arrive on hub delivery threads. The 5 s budget in the tests is a synthetic parameter, and mw-plugin-test passes its own (RenderTimeout, 90 s in the fixtures) in the real gate.

So the five node-plugin repos that gate on mw-plugin-test are not exposed to this. The fault is that the test's source is scheduler-ambient: its delivery depends on what other tests are doing on the shared thread pool.

Fix

Deliver the synthetic frames synchronously on subscribe — the same push shape the real sync stream has — instead of scheduling them on whatever trampoline happens to own the calling thread. Raising the timeout would be wrong twice over: nothing is slow, and the queued item never runs at all, so a larger budget only hangs longer.

Add a deterministic regression pin that installs a foreign CurrentThreadScheduler trampoline and asserts the frames still arrive during Subscribe — that pin fails on today's ToObservable() source and passes on the fix, with no wall clock involved.

Related

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

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions