Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
172 changes: 172 additions & 0 deletions src/MeshWeaver.Fixture/TeardownStragglerCapturer.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,172 @@
using System.Runtime.CompilerServices;

namespace MeshWeaver.Fixture;

/// <summary>
/// Names the teardown straggler behind the "green-but-catastrophic" CI shard failures:
/// <c>Catastrophic failure: System.ObjectDisposedException : Instances cannot be resolved and
/// nested lifetimes cannot be created from this LifetimeScope …</c> with 123/123 passed yet exit 1.
///
/// <para><b>The escape channel is NOT the unobserved-task path.</b> xunit v3 (3.2.2) never hooks
/// <see cref="TaskScheduler.UnobservedTaskException"/> — verified against the shipped binaries
/// (<c>xunit.v3.runner.inproc.console.dll</c> references <c>add_UnhandledException</c> only, no
/// <c>UnobservedTask</c>) — and .NET Core does not escalate unobserved task exceptions
/// (<c>ThrowUnobservedTaskExceptions</c> is off). The producer of the runner <c>ErrorMessage</c>
/// reported as "Catastrophic failure: {0}" is xunit's <see cref="AppDomain.UnhandledException"/>
/// hook in the in-proc console runner (<c>Xunit.Runner.InProc.SystemConsole.ConsoleRunner</c>:
/// <c>AppDomain.CurrentDomain.UnhandledException += … logger.WriteMessage(ErrorMessage.FromException(ex))</c>).
/// It records message only, NO stack — hence "anonymous". That is why the two
/// UnobservedTaskException-based suppressors (<see cref="TestTeardownExceptionSuppressor"/>, the
/// Orleans-local one) never stopped it: wrong event.</para>
///
/// <para><b>The named root (task #20), by this capturer's first-chance stack.</b> The disposed-scope
/// ODE is thrown from Orleans' own connection message pump —
/// <c>Orleans.Runtime.Messaging.Connection.ProcessIncoming</c> → <c>MessageSerializer.TryRead</c> →
/// <c>CodecProvider.TryCreateCodec</c> → <c>ActivatorUtilities.CreateInstance</c> →
/// <c>AutofacServiceProvider.GetService</c> on a disposed <c>LifetimeScope</c>. A silo/client
/// connection is still deserializing an in-flight message while its Autofac container is torn down
/// during <c>TestCluster</c> teardown. Purely Orleans-internal (the #231 mesh drain never covered it);
/// fixed at the disposal seam — <c>OrleansClusterDisposal</c> now runs the graceful
/// <c>StopAllSilosAsync()</c> (which drains the pumps) BEFORE <c>DisposeAsync()</c>. This capturer
/// stays as the permanent net so any future straggler fails with a named stack, not folklore.</para>
///
/// <para><b>What this capturer does</b> — record, never suppress:</para>
/// <list type="number">
/// <item><see cref="AppDomain.FirstChanceException"/>, filtered STRICTLY to the teardown
/// disposed-resource <see cref="ObjectDisposedException"/> shapes (Autofac <c>LifetimeScope</c> +
/// mesh-owned <c>MemoryCache</c> — see <see cref="IsTeardownDisposedStraggler"/>): records the full
/// throw-site stack (<see cref="Environment.StackTrace"/> — at first-chance time the exception's own
/// StackTrace has only the throw frame) + thread/task context. This fires even when the runtime
/// later CATCHES the throw (Orleans caught all 137/137 in a green run), so the throw-site is named
/// without needing the rare unobserved escape. Bounded (cap, cheap filter), so it can live on
/// permanently.</item>
/// <item><see cref="AppDomain.UnhandledException"/> — the channel that actually reds the shard:
/// records the COMPLETE exception (full stack, by now unwound to the callback root) to the
/// test-logs file AND stderr, right next to xunit's anonymous catastrophic line. Future stragglers
/// are named failures, not folklore. The run still fails — nothing is swallowed here.</item>
/// <item><see cref="TaskScheduler.UnobservedTaskException"/>, same strict filter — diagnostics
/// only; observation policy stays in <see cref="TestTeardownExceptionSuppressor"/>.</item>
/// </list>
///
/// <para>Output: <c>{BaseDirectory}/test-logs/teardown-stragglers.log</c> — the CI log-collection
/// step already globs <c>*/bin/*/test-logs/*.log</c> into the run artifacts, so every capture ships
/// automatically.</para>
///
/// <para>NoStaticState note: this is process-lifetime diagnostics infrastructure hooked on
/// process-wide CLR events — there is no mesh to scope it to. It holds no collections; the log FILE
/// is the record, the only mutable statics are bounded counters.</para>
/// </summary>
internal static class TeardownStragglerCapturer
{
private const int FirstChanceCap = 200;

private static int firstChanceCount;
private static int unhandledCount;
private static int unobservedCount;
private static readonly object WriteLock = new();

private static string LogPath =>
Path.Combine(AppContext.BaseDirectory, "test-logs", "teardown-stragglers.log");

[ModuleInitializer]
public static void Init()
{
AppDomain.CurrentDomain.FirstChanceException += static (_, e) =>
{
// Strict filter — only the teardown disposed-resource shapes (Autofac LifetimeScope +
// MemoryCache); everything else is untouched. Recursion safety: nothing our own
// recording code can throw matches this filter.
if (!IsTeardownDisposedStraggler(e.Exception))
return;
var n = Interlocked.Increment(ref firstChanceCount);
if (n > FirstChanceCap)
return;
// Environment.StackTrace at first-chance time = throw site + callers (the exception's
// own StackTrace is not yet unwound past the throw frame).
Append(
$"FIRST-CHANCE #{n} {Header()}\n{e.Exception.GetType().FullName}: {e.Exception.Message}\n{Environment.StackTrace}\n"
+ (n == FirstChanceCap ? "── first-chance capture cap reached; further matches counted but not dumped ──\n" : ""));
};

AppDomain.CurrentDomain.UnhandledException += static (_, e) =>
{
// THIS is the escape that reds a green shard as an anonymous "Catastrophic failure":
// xunit's own hook forwards only the MESSAGE. Name it — full stack, thread context —
// in the CI-collected log AND on stderr. Never swallows; the run still fails.
var n = Interlocked.Increment(ref unhandledCount);
var text =
$"UNHANDLED #{n} (terminating={e.IsTerminating}) {Header()}\n"
+ "── this exception is what xunit reports as the anonymous 'Catastrophic failure' ──\n"
+ (e.ExceptionObject as Exception)?.ToString()
+ $"\n(first-chance disposed-resource captures so far: {Volatile.Read(ref firstChanceCount)})\n";
Append(text);
try
{
Console.Error.WriteLine($"[TeardownStragglerCapturer] {text}");
}
catch
{
// stderr may be gone at process teardown — the file capture above is the record
}
};

TaskScheduler.UnobservedTaskException += static (_, e) =>
{
// Diagnostics only — whether a benign shape gets observed stays the business of
// TestTeardownExceptionSuppressor. Unobserved task exceptions never terminate on
// .NET Core, so these captures explain history, not shard exit codes.
var inners = e.Exception?.Flatten().InnerExceptions;
if (inners is not { Count: > 0 } || !inners.Any(IsTeardownDisposedStraggler))
return;
var n = Interlocked.Increment(ref unobservedCount);
Append($"UNOBSERVED-TASK #{n} {Header()}\n{e.Exception}\n");
};
}

/// <summary>
/// The teardown disposed-resource shapes this capturer names: a late continuation touching a
/// resource whose owning scope has already been torn down. Two known shapes, both
/// <see cref="ObjectDisposedException"/>: (1) the Autofac root container — the Orleans connection
/// message pump resolving a codec from a disposed <c>LifetimeScope</c> (task #20, fixed at
/// <c>OrleansClusterDisposal</c>); (2) a mesh-owned <c>MemoryCache</c> — a late write/read hitting
/// e.g. <c>MeshNodeStreamCache._updateQueues</c> after the cache hub disposed. Both are the same
/// "graceful terminal, never an unobserved throw" defect class (#228/#231 doctrine).
/// </summary>
private static bool IsTeardownDisposedStraggler(Exception? ex) =>
IsAutofacDisposedScope(ex) || IsDisposedMemoryCache(ex);

private static bool IsAutofacDisposedScope(Exception? ex) =>
ex is ObjectDisposedException
&& (ex.Message?.Contains("LifetimeScope", StringComparison.OrdinalIgnoreCase) == true
|| ex.Message?.Contains("nested lifetimes cannot be created", StringComparison.OrdinalIgnoreCase) == true);

private static bool IsDisposedMemoryCache(Exception? ex) =>
ex is ObjectDisposedException ode
&& (string.Equals(ode.ObjectName, "Microsoft.Extensions.Caching.Memory.MemoryCache", StringComparison.Ordinal)
|| ode.Message?.Contains("MemoryCache", StringComparison.OrdinalIgnoreCase) == true);

private static string Header()
{
var t = Thread.CurrentThread;
return $"utc={DateTime.UtcNow:O} thread={t.ManagedThreadId} name='{t.Name}' pool={t.IsThreadPoolThread} "
+ $"taskId={Task.CurrentId?.ToString() ?? "-"} syncCtx={SynchronizationContext.Current?.GetType().Name ?? "-"}";
}

private static void Append(string text)
{
// A capturer must never take the run down: swallow ONLY our own IO faults here (this is
// diagnostics hardening, not suppression of product errors — nothing product-side is caught).
try
{
lock (WriteLock)
{
Directory.CreateDirectory(Path.GetDirectoryName(LogPath)!);
File.AppendAllText(LogPath, $"════ {text}\n");
}
}
catch
{
// disk unavailable at teardown — nothing further we can do
}
}
}
19 changes: 19 additions & 0 deletions src/MeshWeaver.Hosting/MeshNodeStreamCache.cs
Original file line number Diff line number Diff line change
Expand Up @@ -1015,6 +1015,20 @@ private IObservable<MeshNode> UpdateRaw(string path, Func<MeshNode, MeshNode> up
// patches that the RFC 7396 owner-side merge cannot resolve (lists
// collapse to the last writer). Serializing per path makes each
// lambda observe its predecessor's effect.
// DISPOSED-CACHE GUARD (write side): a late write after this cache's Dispose() — the
// canonical case is an agent round whose ThreadExecution.PushToResponseMessage is still
// streaming when its mesh's cacheHub tore down (State captured by TeardownStragglerCapturer:
// UpdateRaw → _updateQueues.TryGetValue → MemoryCache.CheckDisposed) — must NOT touch the
// disposed _updateQueues MemoryCache, whose TryGetValue throws a synchronous
// ObjectDisposedException on the caller's ThreadPool continuation. Unobserved, that reaches
// AppDomain.UnhandledException and xUnit escalates it to a "Catastrophic failure" that reds
// an otherwise-green shard. Dispose() sets _disposed=1 BEFORE it disposes _updateQueues, so
// this flag check (same Volatile idiom as ReleaseIdleReadStreams) fully covers the straggler.
// Return the same graceful Observable.Throw terminal the negative-cache breaker below uses —
// observed by the caller's Subscribe (a benign teardown write), never an unobserved throw.
if (System.Threading.Volatile.Read(ref _disposed) != 0)
return Observable.Throw<MeshNode>(new ObjectDisposedException(nameof(MeshNodeStreamCache)));

// STORM BREAKER (write side): if this path's owner is in a known missing-node failure
// window, fast-fail rather than enqueue another PatchDataRequest the owner can't
// activate. Same negative cache as the read-side GetStreamRaw breaker, so a missing-node
Expand Down Expand Up @@ -1261,6 +1275,11 @@ public IObservable<MeshNode> Overwrite(string path, MeshNode node, JsonSerialize
// Handle.Overwrite (ChangeType.Full) instead of Handle.Update.
private IObservable<MeshNode> OverwriteRaw(string path, MeshNode node)
{
// Disposed-cache guard — see UpdateRaw. A late overwrite after Dispose() must not hit the
// disposed _updateQueues MemoryCache; return a graceful observed terminal, never a throw.
if (System.Threading.Volatile.Read(ref _disposed) != 0)
return Observable.Throw<MeshNode>(new ObjectDisposedException(nameof(MeshNodeStreamCache)));

var queue = GetOrCreateUpdateQueue(path);
var result = new ReplaySubject<MeshNode>();
var seq = System.Threading.Interlocked.Increment(ref _updateSeq);
Expand Down
30 changes: 30 additions & 0 deletions test/MeshWeaver.Hosting.Orleans.Test/OrleansClusterDisposal.cs
Original file line number Diff line number Diff line change
Expand Up @@ -31,13 +31,43 @@ internal static class OrleansClusterDisposal
/// Hand a cluster's disposal to a background pool thread — NEVER awaited on the
/// teardown thread. Null-safe and best-effort (the cluster is on its way down; a
/// shutdown-race exception is benign and swallowed).
///
/// <para><b>Graceful stop BEFORE dispose — the root fix for the Autofac
/// disposed-<c>LifetimeScope</c> straggler (task #20).</b> <see cref="TestCluster.DisposeAsync"/>
/// disposes the Orleans CLIENT host through the generic <c>IHost.DisposeAsync()</c>, which
/// only disposes the service provider and NEVER runs <c>StopAsync()</c>. So the client's
/// connection message pump (<c>Orleans.Runtime.Messaging.Connection.ProcessIncoming</c>) keeps
/// deserializing in-flight messages while the client's Autofac container is being torn down;
/// <c>CodecProvider</c> then lazily resolves a serialization codec from the already-disposed
/// <c>LifetimeScope</c> and throws <see cref="ObjectDisposedException"/> ("Instances cannot be
/// resolved and nested lifetimes cannot be created from this LifetimeScope … already disposed").
/// Unobserved under CI load, that reaches <see cref="AppDomain.UnhandledException"/> — the ONLY
/// channel xUnit v3's in-proc console runner hooks — and is reported as an anonymous
/// "Catastrophic failure" that reds a 123/123-green shard. (The silos are already graceful:
/// <c>InProcessSiloHandle.DisposeAsync</c> runs <c>StopSiloAsync(graceful)</c> first; only the
/// client host skips its <c>StopAsync</c>.) The pump is purely Orleans-internal, so the mesh
/// drain added in #231 (<c>MeshTeardownHostedService</c>) never covered it — and because the
/// client's <c>StopAsync</c> is skipped, that drain never even ran on the client.</para>
///
/// <para><see cref="TestCluster.StopAllSilosAsync"/> stops the client and every silo through
/// their <c>StopAsync</c> lifecycle (client → secondaries → primary), which drains those
/// connection pumps (AND runs <c>MeshTeardownHostedService</c>) so that by the time the
/// containers are disposed nothing is left resolving. Named + measured by
/// <c>TeardownStragglerCapturer</c>: the disposed-scope first-chance throw count per Orleans.Test
/// run drops from ~130 to ~0 once the graceful stop precedes disposal.</para>
/// </summary>
public static void DisposeInBackground(TestCluster? cluster)
{
if (cluster is null)
return;
Pending.Add(Task.Run(async () =>
{
// Graceful ordered stop FIRST (drains client + silo connection pumps before any
// Autofac container is disposed), THEN the dispose. Separate guards so a stop-race
// can't skip the dispose that finishes teardown. Both benign here — the cluster is
// going down; a genuinely surviving straggler is now NAMED by TeardownStragglerCapturer.
try { await cluster.StopAllSilosAsync(); }
catch { /* stop-race on a cluster that's going down — DisposeAsync still completes teardown */ }
try { await cluster.DisposeAsync(); }
catch { /* shutdown-race / zombie silo — benign, the cluster is going down */ }
}));
Expand Down
Loading