diff --git a/memex/Memex.Portal.Shared/MemexConfiguration.cs b/memex/Memex.Portal.Shared/MemexConfiguration.cs index c5ac4ca4c6..c00e8ab7ea 100644 --- a/memex/Memex.Portal.Shared/MemexConfiguration.cs +++ b/memex/Memex.Portal.Shared/MemexConfiguration.cs @@ -204,9 +204,18 @@ public TBuilder ConfigureMemexMesh(IConfiguration configuration, bool isDevelopm // Generations GC — delete only what NO activation entry references and nothing holds // open (skip-on-locked). Landing never deletes anything on a shared volume; this is // the one reclaim point. See ModuleLandingService.CollectGarbage. - var collected = ModuleLandingService.CollectGarbage(moduleRoot); - if (collected > 0) - Console.WriteLine($"[ModuleActivation] modules GC removed {collected} unreferenced generation(s)"); + // + // 🚨 Registered, NEVER run here (#2684). It used to be a synchronous call at this exact + // spot — before the host listened — and on an Azure Files (CIFS) /data the + // rename-then-recursive-delete of orphaned generations is one SMB round-trip per file: + // minutes of uninterruptible IO (PID 1 in `Dsl` at wchan=wait_for_response), no + // listener on :8080, so the 300 s startup probe killed a pod the kernel could not even + // deliver the kill to, and the roll looped (memex-cloud, ci.6559). Housekeeping must + // not gate readiness: the hosted service runs the SAME pass, with the SAME semantics, + // after ApplicationStarted, through the file-system IIoPool. It stays ahead of the + // awaiting-setup early return below on purpose — an instance parked in setup still + // reclaims its garbage, exactly as the synchronous call did. + builder.ConfigureServices(services => services.AddModuleGenerationsGc(moduleRoot)); var persistedActivation = ModuleActivationSidecar.Read(moduleRoot, msg => Console.Error.WriteLine($"[ModuleActivation] {msg}")); var effectiveModules = ModuleActivationBoot.ComputeEffectiveModuleEntries( diff --git a/src/MeshWeaver.Documentation/Data/Architecture/Modules.md b/src/MeshWeaver.Documentation/Data/Architecture/Modules.md index a94bdbc974..cce033e0f1 100644 --- a/src/MeshWeaver.Documentation/Data/Architecture/Modules.md +++ b/src/MeshWeaver.Documentation/Data/Architecture/Modules.md @@ -219,12 +219,12 @@ deployment is ever running an old bundle against a new platform. Inventing a shi is the one thing that must not happen: it mints a SECOND type identity and reintroduces the `as`/`is` trap-door that reads as a silent null. -### 🚨 An ACTIVATED entry with no bytes — the boot-GC race (#2303) +### 🚨 An ACTIVATED entry with no bytes — the GC race (#2303) The "Missing DLL" skip above is the SYMPTOM; #2303 traced one concrete way an entry ends up -pointing at nothing: a race between `ModuleLandingService.CollectGarbage` (run at every pod's boot, -before its own module set is computed) and a landing happening on a DIFFERENT replica at the same -moment. +pointing at nothing: a race between `ModuleLandingService.CollectGarbage` (run once per pod start, +after `ApplicationStarted` — see the readiness section below) and a landing happening on a +DIFFERENT replica at the same moment. A landing is two writes on the shared `/data` volume, deliberately ordered bytes-then-entry: it `Directory.Move`s the new generation into place, THEN writes the sidecar entry that names it @@ -286,6 +286,30 @@ that had landed long ago, on both prods at once: The pin is protection, not a gate: a boot that cannot copy warns loudly and falls back to the shared path. +### 🚨 GC is OFF the readiness path (#2684) + +Where the pass runs is as load-bearing as what it deletes. It used to run synchronously in the +portal's boot path — before the host listened — and on an Azure Files (CIFS) `/data` the +rename-then-recursive-delete of orphaned generations is one SMB round-trip per file: minutes of +uninterruptible IO for a handful of directories. Rollout time thereby became a function of how much +garbage the previous generation left on a network volume, which is unbounded and invisible until +the probe kills the pod: memex-cloud's roll to ci.6559 sat as PID 1 in `Dsl` at +`wchan=wait_for_response`, never bound :8080, blew the 300 s startup probe — whose kill cannot land +on a process parked in uninterruptible IO — and looped, wedging the whole `helm upgrade`. Raising +the probe budget would only move the cliff. + +Reclaiming orphans is housekeeping: valid at any time, needed by nothing the portal serves. So the +pass now runs from `ModuleGenerationsGcHostedService`, registered by the same boot path that used +to call it: `StartAsync` only registers an `ApplicationStarted` callback (it can never delay the +listener), the callback schedules `CollectGarbage` on the file-system `IIoPool`, and the pass +observes the pool's cancellation between directories so a mesh teardown never waits out a slow +unlink. Nothing about the pass gates `/health` or `/alive`, and nothing about its SEMANTICS +changed: same rules, same grace window, same atomic `.trash-*` rename — and the reference set is +re-read from the per-module sidecar files at run time, so a post-start pass sees a set at least as +fresh as the boot-time pass did. The running process is immune to its own reclaim because it loads +store-landed generations from the process-local pin (above), never the shared tree — the same +property that already protected it from a SIBLING pod's pass. + Why a sidecar file and not a mesh node: the list is consumed before any storage provider, hub, or connection string exists, and it must move with the DLLs it describes — the landing service writes both in one operation onto the same volume, so they cannot drift apart. diff --git a/src/MeshWeaver.Documentation/Data/WhatsNew/2026-08-30-module-cleanup-no-longer-delays-a-restart.md b/src/MeshWeaver.Documentation/Data/WhatsNew/2026-08-30-module-cleanup-no-longer-delays-a-restart.md new file mode 100644 index 0000000000..34dcaed5b2 --- /dev/null +++ b/src/MeshWeaver.Documentation/Data/WhatsNew/2026-08-30-module-cleanup-no-longer-delays-a-restart.md @@ -0,0 +1,20 @@ +--- +Name: Module cleanup no longer delays a restart +Category: Fix +Description: Cleaning up leftover module files now happens after the portal is already serving, so a restart can never hang on slow storage doing housekeeping. +Icon: Sparkle +Order: -20260830 +--- + +# Module cleanup no longer delays a restart + +When the portal starts, it tidies up module files that older versions left behind. On deployments +whose data lives on network storage, that tidying can take minutes — and it used to run *before* +the portal started answering requests. A restart could therefore look stuck for so long that the +platform gave up, killed the starting portal, and tried again, in a loop: an update that never +completed, caused entirely by cleanup work nobody was waiting for. + +The cleanup now runs right after the portal is up and serving. Restarts and updates come up as fast +as the portal itself, regardless of how much there is to tidy — and the tidying still happens, with +exactly the same care as before: nothing in use is ever touched, and anything a busy moment skips +is picked up on a later pass. diff --git a/src/MeshWeaver.PluginCatalog/ModuleGenerationsGcHostedService.cs b/src/MeshWeaver.PluginCatalog/ModuleGenerationsGcHostedService.cs new file mode 100644 index 0000000000..d0261dd746 --- /dev/null +++ b/src/MeshWeaver.PluginCatalog/ModuleGenerationsGcHostedService.cs @@ -0,0 +1,174 @@ +using System.Reactive.Subjects; +using MeshWeaver.Mesh.Threading; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Microsoft.Extensions.Logging; + +namespace MeshWeaver.PluginCatalog; + +/// +/// Runs the modules/ generations GC () OFF the readiness path — after +/// , through the file-system +/// (#2684). +/// +/// 🚨 Why the boot path is the wrong place. The pass used to run synchronously in +/// ConfigureMemexMesh, before the host listened. Reclaiming orphaned generations is one SMB +/// round-trip per file on an Azure Files (CIFS) /data — minutes of uninterruptible IO for a +/// handful of leftover directories — and it reclaims nothing the portal needs in order to SERVE. +/// Rollout time therefore became a function of how much garbage the previous generation left on a +/// network volume: memex-cloud's roll to ci.6559 sat as PID 1 in Dsl at +/// wchan=wait_for_response deleting a .trash-* generation, never bound :8080, blew +/// the 300 s startup probe (whose kill cannot land on a process parked in uninterruptible IO), and +/// looped. Raising the probe budget would only move the cliff; the GC has no business in front of +/// the listener at all. +/// +/// The semantics do not change — only the WHEN. Same pass, same rules: delete only +/// what no activation entry references and nothing holds open (skip-on-locked), landing never +/// deletes, the atomic .trash-* rename (#2509), the #2303 grace window, fail-closed on an +/// unreadable reference set. The reference set is re-read from the per-module sidecar files at run +/// time, so a post-start pass sees a set at least as fresh as the boot-time pass did — and the +/// running process is immune to its own reclaim because boot loads store-landed generations from a +/// process-local pinned copy (), never the shared tree. +/// +/// Lifecycle. only registers the +/// ApplicationStarted callback — it can never delay the listener, and nothing here gates +/// /health or /alive. The callback schedules the pass on the pool and returns; the +/// blocking work runs on the pool's limited-concurrency scheduler with the pool's cancellation +/// linked in, so a mesh teardown cancels a sweep still crawling a slow volume instead of waiting +/// on it (the token is observed between directories — the unit of atomic removal). +/// +public sealed class ModuleGenerationsGcHostedService : IHostedService, IDisposable +{ + /// The pass itself — a test seam. Production is + /// ; a test substitutes a collector it can block or count, which is how + /// "readiness never waits on a stalled sweep" is provable without a real CIFS mount. + public delegate int Collector(string moduleRoot, ILogger? logger, CancellationToken cancellationToken); + + private readonly string moduleRoot; + private readonly IHostApplicationLifetime lifetime; + private readonly IIoPool pool; + private readonly ILogger? logger; + private readonly Collector collect; + // One-shot terminal state: the count once the pass finished, or its error. AsyncSubject so a + // subscriber arriving after the sweep (a test, a diagnostic) still gets the outcome. + private readonly AsyncSubject completed = new(); + private IDisposable? startedRegistration; + private IDisposable? sweep; + + /// Creates the service. + /// The deployment root the modules/ tree lives under — the + /// SAME resolved root the boot path computes effective modules from (), + /// never AppContext.BaseDirectory directly. + /// The host lifetime whose ApplicationStarted gates the pass — + /// it fires only once every hosted service (Kestrel's listener included) has started. + /// The bounded IO pool the blocking filesystem pass runs through. + /// Diagnostics — the removal count is reported exactly as the boot-path + /// call reported it. + /// Test seam for the pass; see . + public ModuleGenerationsGcHostedService( + string moduleRoot, + IHostApplicationLifetime lifetime, + IIoPool pool, + ILogger? logger = null, + Collector? collect = null) + { + this.moduleRoot = moduleRoot; + this.lifetime = lifetime; + this.pool = pool; + this.logger = logger; + this.collect = collect ?? ((root, log, ct) => + ModuleLandingService.CollectGarbage(root, log, cancellationToken: ct)); + } + + /// + /// The pass's terminal outcome: emits the removed-directory count once the sweep finished, + /// errors when it faulted, and stays silent while it has not run. Tests and diagnostics wait + /// on this — readiness never does. + /// + public IObservable Completed => completed; + + /// + public Task StartAsync(CancellationToken cancellationToken) + { + // 🚨 Register only — no filesystem IO before the host listens (#2684). ApplicationStarted + // fires after EVERY hosted service has started, i.e. strictly after the listener is bound. + startedRegistration = lifetime.ApplicationStarted.Register(KickSweep); + return Task.CompletedTask; + } + + private void KickSweep() + { + // InvokeBlocking: the pass is synchronous, blocking filesystem IO — it runs on the pool's + // limited-concurrency scheduler, with the pool's own cancellation linked in, so it can + // neither starve the ThreadPool nor outlive a teardown drain (the collector observes the + // token between directories). + sweep = pool.InvokeBlocking(ct => collect(moduleRoot, logger, ct)) + .Subscribe( + removedCount => + { + if (removedCount > 0) + logger?.LogInformation( + "[ModuleActivation] modules GC removed {Count} unreferenced generation(s)", + removedCount); + completed.OnNext(removedCount); + completed.OnCompleted(); + }, + ex => + { + // A faulted pass reclaims nothing and breaks nothing: every state it can leave + // behind (an intact orphan, a .trash-* remainder) is one a later pass — the + // next pod start — already plans for. Surfaced, never swallowed. + logger?.LogWarning(ex, + "[ModuleActivation] modules GC pass over {ModuleRoot} faulted — nothing " + + "was collected; the next pod start plans it again.", moduleRoot); + completed.OnError(ex); + }); + } + + /// + public Task StopAsync(CancellationToken cancellationToken) + { + Dispose(); + return Task.CompletedTask; + } + + /// + public void Dispose() + { + startedRegistration?.Dispose(); + startedRegistration = null; + // Unsubscribing cancels the pooled leaf's linked token — a sweep still crawling a slow + // volume stops at its next between-directories check instead of parking the drain. The + // AsyncSubject is deliberately NOT disposed: a leaf mid-completion may still be delivering + // its terminal notification on a pool thread, and OnNext into a disposed subject throws + // where nothing can observe it. The subject holds no resources; it dies with the service. + sweep?.Dispose(); + sweep = null; + } +} + +/// Registration for the post-start modules/ generations GC. +public static class ModuleGenerationsGcExtensions +{ + /// + /// Registers over . + /// Two-registration idiom: the IHostedService forward is what STARTS it; the concrete + /// singleton is resolvable for tests and diagnostics (). + /// + /// The host's service collection. + /// The resolved module root — the same one the boot path computed its + /// effective module set from. + public static IServiceCollection AddModuleGenerationsGc( + this IServiceCollection services, string moduleRoot) + => services + .AddSingleton(sp => new ModuleGenerationsGcHostedService( + moduleRoot, + sp.GetRequiredService(), + sp.GetService()?.Get(IoPoolNames.FileSystem) ?? IoPool.Unbounded, + sp.GetService>())) + .AddSingleton(sp => + sp.GetRequiredService()); +} diff --git a/src/MeshWeaver.PluginCatalog/ModuleLandingService.cs b/src/MeshWeaver.PluginCatalog/ModuleLandingService.cs index bb32235fb0..2b6a63c7ff 100644 --- a/src/MeshWeaver.PluginCatalog/ModuleLandingService.cs +++ b/src/MeshWeaver.PluginCatalog/ModuleLandingService.cs @@ -58,9 +58,9 @@ namespace MeshWeaver.PluginCatalog; /// replicas landing different modules share no path, cannot lose each other's entry, and never /// contend for one file's SMB lease. /// -/// …except boot-time GC against a CONCURRENT landing (#2303). A landing's two writes +/// …except a GC pass against a CONCURRENT landing (#2303). A landing's two writes /// (move the bytes, then ) are not atomic across -/// replicas, so another replica's can observe the new generation +/// replicas, so another replica's can observe the new generation /// directory before the entry that claims it exists and delete it as "unreferenced" — leaving a /// real activation entry pointing at nothing a moment later. See /// for the race and the grace-period fix. @@ -79,7 +79,7 @@ public static string ModuleDirectoryFor( /// /// How long an UNREFERENCED directory under modules/ must sit before - /// treats it as truly orphaned rather than the first half of a + /// treats it as truly orphaned rather than the first half of a /// landing this replica has not seen the SECOND half of yet — the race behind #2303. /// /// 🚨 The race. A landing is two writes on the shared /data volume, @@ -111,7 +111,7 @@ public static string ModuleDirectoryFor( public static readonly TimeSpan DefaultGarbageMinAge = TimeSpan.FromMinutes(5); /// - /// Boot-time garbage collection over modules/: deletes generation directories + /// Garbage collection over modules/: deletes generation directories /// (<name>@<id>) no activation entry references, leftover /// .staging-*, .trash-* from an earlier pass's interrupted delete, and the /// retired .pending-* folders of the abandoned deferred-swap scheme — but (except for @@ -128,7 +128,7 @@ public static string ModuleDirectoryFor( /// set deleted the very bytes the entry references — the dangling activation entries #2509 /// measured on both prods. So any read fault skips every generation delete this pass /// (transient .staging-/.pending-/.trash- folders still collect — nothing references - /// those by design); a later boot re-reads and sweeps then. Unreadable is never unreferenced. + /// those by design); a later pass re-reads and sweeps then. Unreadable is never unreferenced. /// /// 🚨 Removal is atomic per directory (#2509). A generation is first renamed to a /// .trash-* sibling — one atomic rename, after which it no longer exists as far as @@ -139,6 +139,18 @@ public static string ModuleDirectoryFor( /// 'OpenAI' shape of the 2026-08-27 outage. With rename-first, a refused rename (held open /// on SMB) leaves the directory fully intact, and an interrupted delete leaves only a /// .trash-* folder a later pass finishes. There is no half-deleted state either way. + /// + /// 🚨 Housekeeping — never a readiness step (#2684). On an Azure Files (CIFS) + /// /data this is one SMB round-trip per file, which is MINUTES for a handful of + /// orphaned generations — and it reclaims nothing the portal needs in order to SERVE. It used + /// to run synchronously in the portal's boot path, before the host listened, so rollout time + /// became a function of how much garbage the previous generation left on a network volume: + /// the pass blew the 300 s startup probe, the kill could not land on a process parked in + /// uninterruptible IO (Dsl, wchan=wait_for_response), and the roll looped. It now + /// runs from once ApplicationStarted has + /// fired, on the file-system IIoPool, and observes + /// between directories so a mesh teardown is never parked behind a slow unlink. Nothing here + /// gates /health or /alive. /// /// The deployment root whose modules/ folder is swept. /// Diagnostics — every removal and every age-deferred skip is logged. @@ -147,19 +159,26 @@ public static string ModuleDirectoryFor( /// The reference "now" the age check compares against. Defaults to /// ; a test seam so the race and its fix are provable without a /// real sleep. + /// Observed BETWEEN directories — the unit of atomic removal. + /// A cancelled pass stops before its next rename and returns what it removed so far; whatever + /// is left (an intact orphan, or a .trash-* whose delete did not finish) is a later + /// pass's job by construction. This is the pool's token when the pass runs through + /// IIoPool, so a mesh teardown cancels the sweep instead of waiting on it. /// How many directories were removed — where "removed" means gone from the /// modules/ namespace (a rename into .trash-* counts even when the final delete /// is finished by a later pass). public static int CollectGarbage( - string baseDirectory, ILogger? logger = null, TimeSpan? minAge = null, DateTime? nowUtc = null) - => CollectGarbage(baseDirectory, logger, minAge, nowUtc, deleteDirectory: null); + string baseDirectory, ILogger? logger = null, TimeSpan? minAge = null, DateTime? nowUtc = null, + CancellationToken cancellationToken = default) + => CollectGarbage(baseDirectory, logger, minAge, nowUtc, deleteDirectory: null, cancellationToken); /// The implementation behind with the delete operation as a seam, so the interrupted-delete path — the one - /// that used to leave a half-gutted generation — is provable in a test without a real SMB lock. + /// DateTime?, CancellationToken)"/> with the delete operation as a seam, so the interrupted-delete + /// path — the one that used to leave a half-gutted generation — is provable in a test without a + /// real SMB lock. internal static int CollectGarbage( string baseDirectory, ILogger? logger, TimeSpan? minAge, DateTime? nowUtc, - Action? deleteDirectory) + Action? deleteDirectory, CancellationToken cancellationToken = default) { var modulesRoot = Path.Combine(baseDirectory, "modules"); if (!Directory.Exists(modulesRoot)) @@ -184,6 +203,16 @@ internal static int CollectGarbage( var removed = 0; foreach (var dir in Directory.EnumerateDirectories(modulesRoot)) { + // 🚨 Between directories, never mid-removal: a rename is atomic, and a .trash-* whose + // delete was cut short is exactly the state a later pass already finishes (#2509). The + // token is the IIoPool's (#2684) — a teardown drain must not wait out a slow unlink. + if (cancellationToken.IsCancellationRequested) + { + logger?.LogInformation( + "Modules GC: cancelled after removing {Removed} directory(ies) — the rest is a " + + "later pass's job.", removed); + break; + } var leaf = Path.GetFileName(dir); var isTrash = leaf.StartsWith(".trash-", StringComparison.OrdinalIgnoreCase); var isTransient = isTrash @@ -198,7 +227,7 @@ internal static int CollectGarbage( logger?.LogWarning( "Modules GC: {Faults} activation entry file(s) could not be read, so the " + "reference set is incomplete — SKIPPING every generation delete this pass " - + "(unreadable is never unreferenced, #2509). A later boot re-reads and " + + "(unreadable is never unreferenced, #2509). A later pass re-reads and " + "sweeps.", readFaults); reportedUnreliable = true; continue; @@ -221,7 +250,7 @@ internal static int CollectGarbage( if (isOrphanGeneration) { // Atomic removal (#2509): one rename takes the generation out of the modules/ - // namespace; a refusal (held open on SMB) leaves it FULLY intact for the next boot. + // namespace; a refusal (held open on SMB) leaves it FULLY intact for a later pass. var trash = Path.Combine(modulesRoot, $".trash-{leaf}-{Guid.NewGuid():N}"[..(".trash-".Length + leaf.Length + 9)]); try @@ -232,7 +261,7 @@ internal static int CollectGarbage( } catch (Exception e) when (e is IOException or UnauthorizedAccessException) { - // Held open by a still-running pod — intact, the next boot collects it. + // Held open by a still-running pod — intact, a later pass collects it. logger?.LogDebug("Modules GC: {Dir} is in use, skipped ({Reason})", leaf, e.Message); continue; } @@ -514,8 +543,8 @@ private ModuleLandingOutcome LandCore( // volume: an open file refuses deletion on SMB (the 409s), and the boot-time deferred // apply raced the OTHER pods of a rolling restart — deletes half-succeeded and 13 of 15 // module closures were reduced to their entry DLL (2026-08-20). Old generations are - // garbage-collected at boot (CollectGarbage), skip-on-locked, once no entry references - // them. + // garbage-collected by the post-start GC pass (ModuleGenerationsGcHostedService → + // CollectGarbage), skip-on-locked, once no entry references them. var modulesRoot = Path.Combine(baseDirectory, "modules"); var generation = $"{name}@{Guid.NewGuid():N}"[..(name.Length + 9)]; var target = Path.Combine(modulesRoot, generation); @@ -610,7 +639,7 @@ private void RemoveCore(string name) + "publish-laid-out module folders are managed by the deployment, not uninstall."); // The generation pointer is CLEARED on uninstall — a disabled entry must not keep its - // directory 'referenced', or boot GC could never reclaim it. Written to THIS module's own + // directory 'referenced', or the GC pass could never reclaim it. Written to THIS module's own // file, never through the shared index (#2090): an uninstall racing another module's // landing used to drop whichever entry lost. ModuleActivationSidecar.WriteEntry(baseDirectory, @@ -619,7 +648,8 @@ private void RemoveCore(string name) // Best-effort immediate delete: on a shared volume the files of a LOADED module refuse // deletion (SMB keeps them open) — that is fine, the cleared pointer above makes the - // next boot's CollectGarbage reclaim the generation once no pod holds it. + // next GC pass (ModuleGenerationsGcHostedService, after a pod's ApplicationStarted) + // reclaim the generation once no pod holds it. var targets = new List { Path.Combine(baseDirectory, "modules", name) }; if (!string.IsNullOrWhiteSpace(existing.Directory)) targets.Add(Path.Combine(baseDirectory, "modules", existing.Directory!)); @@ -632,7 +662,7 @@ private void RemoveCore(string name) catch (Exception e) when (e is IOException or UnauthorizedAccessException) { logger?.LogDebug( - "Uninstall of '{Name}': {Dir} is in use, boot GC reclaims it ({Reason})", + "Uninstall of '{Name}': {Dir} is in use, the next GC pass reclaims it ({Reason})", name, Path.GetFileName(target), e.Message); } } diff --git a/test/Memex.Portal.Shared.Test/ModuleGcOffReadinessPathTest.cs b/test/Memex.Portal.Shared.Test/ModuleGcOffReadinessPathTest.cs new file mode 100644 index 0000000000..5113f75fac --- /dev/null +++ b/test/Memex.Portal.Shared.Test/ModuleGcOffReadinessPathTest.cs @@ -0,0 +1,105 @@ +using System.Reactive.Linq; +using System.Reactive.Threading.Tasks; +using Memex.Portal.Shared; +using MeshWeaver.Mesh; +using MeshWeaver.Messaging; +using MeshWeaver.PluginCatalog; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Microsoft.Extensions.Hosting.Internal; +using Microsoft.Extensions.Logging.Abstractions; +using Xunit; + +namespace Memex.Portal.Shared.Test; + +/// +/// #2684, pinned: the portal boot path must NEVER run the modules/ generations GC before +/// the host listens. On an Azure Files (CIFS) /data the rename-then-recursive-delete of +/// orphaned generations is one SMB round-trip per file — minutes of uninterruptible IO — and it +/// reclaims nothing the portal needs in order to SERVE. When it ran synchronously in +/// ConfigureMemexMesh, rollout time became a function of how much garbage the previous +/// generation left on a network volume: memex-cloud's roll to ci.6559 sat as PID 1 in Dsl +/// deleting a .trash-* generation, never bound :8080, blew the 300 s startup probe (whose +/// kill cannot land on a process parked in uninterruptible IO), and looped. +/// +/// This test drives the REAL boot path (ConfigureMemexMesh) over a module root that +/// contains a genuine orphan generation and asserts the three phases in order: configuring the +/// mesh does not collect it, starting the hosted services (everything that happens before the +/// listener is up) does not collect it, and only ApplicationStarted — the signal that fires +/// strictly after the host listens — triggers the pass that does. Reclaim is deferred, never +/// dropped: the orphan IS collected afterwards. +/// +public class ModuleGcOffReadinessPathTest +{ + [Fact] + public async Task TheBootPathDefersGenerationsGc_UntilTheHostListens_ThenStillReclaims() + { + var root = Directory.CreateTempSubdirectory("mw-2684-").FullName; + try + { + // A genuine orphan: a generation directory no activation entry references, backdated + // past the #2303 grace window so only the WHEN of the pass — not the grace period — + // decides its fate. + var modules = Path.Combine(root, "modules"); + var orphan = Path.Combine(modules, "MeshWeaver.Widget@dead0001"); + Directory.CreateDirectory(orphan); + File.WriteAllText(Path.Combine(orphan, "MeshWeaver.Widget.dll"), "ORPHAN"); + Directory.SetLastWriteTimeUtc(orphan, + DateTime.UtcNow - ModuleLandingService.DefaultGarbageMinAge - TimeSpan.FromMinutes(1)); + + var configuration = new ConfigurationBuilder() + .AddInMemoryCollection(new Dictionary + { + ["Graph:Storage:Type"] = "FileSystem", + ["Graph:Storage:BasePath"] = root, + ["Modules:Root"] = root, + }) + .Build(); + var services = new ServiceCollection(); + services.AddLogging(); + // The REAL host-lifetime implementation (the generic host's own), so ApplicationStarted + // has production semantics: registered callbacks run when NotifyStarted fires — which + // the host does strictly AFTER every hosted service (the listener included) started. + var lifetime = new ApplicationLifetime(NullLogger.Instance); + services.AddSingleton(lifetime); + + new MeshBuilder(configure => configure(services), new Address("mesh", "test")) + .ConfigureMemexMesh(configuration); + + // Phase 1 — the boot path itself. This is where the synchronous CollectGarbage call + // used to live; the orphan surviving it is the fix. + Assert.True(Directory.Exists(orphan), + "ConfigureMemexMesh must not collect garbage synchronously — that pass on a CIFS " + + "/data is what blew the 300 s startup probe (#2684)"); + + await using var provider = services.BuildServiceProvider(); + var gc = provider.GetRequiredService(); + + // Phase 2 — hosted-service StartAsync: everything that runs BEFORE the host listens. + await gc.StartAsync(CancellationToken.None); + Assert.True(Directory.Exists(orphan), + "StartAsync runs before the listener is bound, so it must only register the " + + "ApplicationStarted callback — never sweep"); + + // Phase 3 — the host is listening. Reclaim is deferred, not dropped. + lifetime.NotifyStarted(); + var removed = await gc.Completed + .Timeout(TimeSpan.FromSeconds(30)) + .FirstAsync() + .ToTask(TestContext.Current.CancellationToken); + Assert.Equal(1, removed); + Assert.False(Directory.Exists(orphan), + "the post-start pass must still reclaim the orphan — off the readiness path is " + + "not off the roster"); + Assert.Empty(Directory.EnumerateDirectories(modules, ".trash-*")); + + await gc.StopAsync(CancellationToken.None); + } + finally + { + try { Directory.Delete(root, recursive: true); } + catch { /* temp cleanup is the OS's problem, never a test failure */ } + } + } +} diff --git a/test/MeshWeaver.PluginCatalog.Test/GenerationGcHardeningTest.cs b/test/MeshWeaver.PluginCatalog.Test/GenerationGcHardeningTest.cs index 6598ba1dbc..f9058bca3e 100644 --- a/test/MeshWeaver.PluginCatalog.Test/GenerationGcHardeningTest.cs +++ b/test/MeshWeaver.PluginCatalog.Test/GenerationGcHardeningTest.cs @@ -106,6 +106,50 @@ public void CollectGarbage_RemovalIsAtomic_AnInterruptedDeleteLeavesNoHalfGutted Assert.Empty(Directory.EnumerateDirectories(Modules, ".trash-*")); } + /// + /// #2684: the pass observes cancellation BETWEEN directories — the unit of atomic removal — so + /// a teardown drain never waits out a sweep crawling a slow CIFS volume. A cancelled pass + /// stops before its next rename and leaves only states a later pass already plans for: an + /// intact orphan, or nothing (the in-flight removal completes, it is never torn mid-rename). + /// + [Fact] + public void CollectGarbage_StopsBetweenDirectories_WhenCancelled() + { + Write("MeshWeaver.A@dead0001", "MeshWeaver.A.dll", "DEAD"); + Write("MeshWeaver.B@dead0002", "MeshWeaver.B.dll", "DEAD"); + Backdate(Path.Combine(Modules, "MeshWeaver.A@dead0001")); + Backdate(Path.Combine(Modules, "MeshWeaver.B@dead0002")); + + // Already cancelled: the pass removes NOTHING — it never reaches a rename. + var none = ModuleLandingService.CollectGarbage( + root, cancellationToken: new CancellationToken(canceled: true)); + Assert.Equal(0, none); + Assert.True(Directory.Exists(Path.Combine(Modules, "MeshWeaver.A@dead0001"))); + Assert.True(Directory.Exists(Path.Combine(Modules, "MeshWeaver.B@dead0002"))); + + // Cancelled MID-pass (from inside the first removal's delete): the in-flight removal + // completes atomically, and the loop stops before touching the second directory. + using var cts = new CancellationTokenSource(); + var removed = ModuleLandingService.CollectGarbage( + root, logger: null, minAge: null, nowUtc: null, + deleteDirectory: dir => + { + cts.Cancel(); + Directory.Delete(dir, recursive: true); + }, + cancellationToken: cts.Token); + + Assert.Equal(1, removed); + var survivors = Directory.EnumerateDirectories(Modules) + .Where(d => Path.GetFileName(d).Contains('@')) + .ToArray(); + Assert.Single(survivors); + Assert.Empty(Directory.EnumerateDirectories(Modules, ".trash-*")); + + // Deferred is not dropped: an uncancelled later pass reclaims the survivor. + Assert.Equal(1, ModuleLandingService.CollectGarbage(root)); + } + [Fact] public void PinnedLoadPath_SurvivesTheSharedGenerationBeingReclaimed() { diff --git a/test/MeshWeaver.PluginCatalog.Test/ModuleGenerationsGcHostedServiceTest.cs b/test/MeshWeaver.PluginCatalog.Test/ModuleGenerationsGcHostedServiceTest.cs new file mode 100644 index 0000000000..ced22f3ddc --- /dev/null +++ b/test/MeshWeaver.PluginCatalog.Test/ModuleGenerationsGcHostedServiceTest.cs @@ -0,0 +1,104 @@ +using System.Reactive; +using System.Reactive.Linq; +using System.Reactive.Subjects; +using System.Reactive.Threading.Tasks; +using MeshWeaver.Mesh.Threading; +using MeshWeaver.PluginCatalog; +using Microsoft.Extensions.Hosting.Internal; +using Microsoft.Extensions.Logging.Abstractions; +using Xunit; + +namespace MeshWeaver.PluginCatalog.Test; + +/// +/// The #2684 contract of : the generations GC is +/// housekeeping that runs AFTER ApplicationStarted — never in StartAsync, which the +/// host awaits before it can listen — and a pass stalled in slow IO (the CIFS Dsl park that +/// blew memex-cloud's startup probe) can neither delay the started callback nor survive teardown: +/// disposing the service cancels the pooled leaf's token and the collector unwinds. +/// +public class ModuleGenerationsGcHostedServiceTest : IDisposable +{ + private readonly IoPool pool = new(1); + private readonly ApplicationLifetime lifetime = new(NullLogger.Instance); + + public void Dispose() => pool.Dispose(); + + [Fact] + public async Task TheSweepRunsOnlyAfterApplicationStarted() + { + var invoked = 0; + var svc = new ModuleGenerationsGcHostedService( + "(unused)", lifetime, pool, + collect: (_, _, _) => + { + Interlocked.Increment(ref invoked); + return 7; + }); + + await svc.StartAsync(CancellationToken.None); + + // FIFO probe through the same cap-1 pool: had StartAsync scheduled the sweep, it would + // have run before this probe completed. A positive signal, not a sleep. + await pool.InvokeBlocking(_ => 0).FirstAsync().ToTask(TestContext.Current.CancellationToken); + Assert.Equal(0, Volatile.Read(ref invoked)); + + lifetime.NotifyStarted(); + var removed = await svc.Completed + .Timeout(TimeSpan.FromSeconds(10)) + .FirstAsync() + .ToTask(TestContext.Current.CancellationToken); + + Assert.Equal(7, removed); + Assert.Equal(1, Volatile.Read(ref invoked)); + await svc.StopAsync(CancellationToken.None); + } + + [Fact] + public async Task AStalledSweepNeverBlocksTheStartedCallback_AndTeardownCancelsIt() + { + var entered = new AsyncSubject(); + var unwound = new AsyncSubject(); + var svc = new ModuleGenerationsGcHostedService( + "(unused)", lifetime, pool, + collect: (_, _, ct) => + { + entered.OnNext(Unit.Default); + entered.OnCompleted(); + // The CIFS stall, simulated on the pool thread: the collector makes no progress + // until the pooled leaf's token cancels — the state memex-cloud's PID 1 sat in + // (#2684). Deliberately a cooperative spin, NOT a kernel wait: a blocking bridge + // in a test is the #2013 defect class (BlockingBridgeInTestRatchetGuard), and the + // property under test is precisely that nothing on the host side ever waits on + // this thread. The 30 s ceiling means even a broken cancellation path cannot park + // the thread past this test's own Timeout assertions. + var stall = System.Diagnostics.Stopwatch.StartNew(); + var spin = new SpinWait(); + while (!ct.IsCancellationRequested && stall.Elapsed < TimeSpan.FromSeconds(30)) + spin.SpinOnce(); + if (ct.IsCancellationRequested) + { + unwound.OnNext(Unit.Default); + unwound.OnCompleted(); + } + return 0; + }); + + await svc.StartAsync(CancellationToken.None); + + // NotifyStarted runs registered callbacks INLINE — if the sweep ran inside the callback + // rather than being scheduled on the pool, this line would park forever on the stall + // (and the test's timeout would name it). + lifetime.NotifyStarted(); + + // The sweep IS running (on a pool thread), parked in its "IO". + await entered.Timeout(TimeSpan.FromSeconds(10)).FirstAsync() + .ToTask(TestContext.Current.CancellationToken); + + // Teardown: disposing the service unsubscribes the pooled leaf, which cancels its linked + // token — the stalled collector unwinds instead of parking the drain. + await svc.StopAsync(CancellationToken.None); + await unwound.Timeout(TimeSpan.FromSeconds(10)).FirstAsync() + .ToTask(TestContext.Current.CancellationToken); + } +}