From e004eed2cc0d573923966c3c358fed73b31115a6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Roland=20B=C3=BCrgi?= Date: Tue, 28 Jul 2026 07:08:49 +0100 Subject: [PATCH] Compile discovery: read sources directly instead of through the live synced query MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A compile needs a POINT-IN-TIME snapshot of its sources. It was taking that snapshot from the cached SYNCED query, which exists to deliver LIVE updates — a guarantee a compile does not need and, on a large mesh, pays 45 seconds for. Measured on memex, same box, same data, same four queries a Store/Coupon compile issues: via IMeshService.Query (what MCP `search` uses) ~0.25s counts 16 / 4 / 1 via the cached synced query (what compiles used) 45.20s 45.20s is one SyncStreamOptions.HeartbeatInterval to within 200ms: the synced subscription misses its Initial and idles until the periodic heartbeat re-delivers. Roslyn itself is 2.83s, so 97% of every compile was that wait — and types then crossed the 60s settle window, which is how every plugin root came to serve the "did not settle" fallback on 2026-07-27. Everything else was eliminated by experiment BEFORE writing this, which is the part the earlier attempts skipped: - the compile path itself 0ms discovery on a fresh mesh (issue #686) - topology 0ms with ONE silo and with TWO (real AdoNet cluster, both silos Active) — silo count is not the cause - scale / ~90 schemas the same queries answer in 0.25s ON memex - the heartbeat schedule #684 shipped and measured no change (48s → 57s) - pre-warming enabled on memex, degraded 7 of 16 roots, rolled back So: direct read FIRST, synced query kept only as a fallback when the direct read finds nothing. Never the other way round. #682 kept the cache primary and raced a delayed probe against it — that probe never fired once in production, and this ordering is exactly what removes the dependency on winning a race. 647/647 Graph, 8/8 Hosting.Monolith compile/pre-warm integration tests. Co-Authored-By: Claude Opus 5 (1M context) --- .../MeshNodeCompilationService.cs | 67 ++++++++++--------- 1 file changed, 37 insertions(+), 30 deletions(-) diff --git a/src/MeshWeaver.Graph/Configuration/MeshNodeCompilationService.cs b/src/MeshWeaver.Graph/Configuration/MeshNodeCompilationService.cs index 6c9403a2b2..98608f53d9 100644 --- a/src/MeshWeaver.Graph/Configuration/MeshNodeCompilationService.cs +++ b/src/MeshWeaver.Graph/Configuration/MeshNodeCompilationService.cs @@ -478,35 +478,44 @@ private IObservable> SnapshotSources( NodeTypeDefinition? ntDef, string selfPath, IReadOnlyList? sourcesOverride) { var bound = _cacheOptions.SourceSnapshotTimeout; - var cached = ResolveSources(ntDef, selfPath, sourcesOverride).Take(1); - - // 🚨 THE 90-SECOND COMPILE. An override is already a direct snapshot, but the CACHED synced - // query has a lost-wakeup mode: when its subscription misses the Initial, nothing re-requests - // — the read simply idles until the sync stream's periodic HEARTBEAT (45s, - // SyncStreamOptions.HeartbeatInterval) re-delivers the content. memex, 2026-07-27: a - // Store/Plugin compile spent 90.19s — TWO missed heartbeats — between "Invoking compiler…" - // and its source queries resolving, while Roslyn itself took 2.6s. Every plugin root then - // blew the 60s settle window and served the "did not settle" fallback; the site was down. - // - // So RACE the cached query against a direct, uncached mesh read of the SAME expanded - // queries. Healthy path: the cache answers instantly and the probe never runs (it is - // subscription-delayed, so it costs nothing). Stalled path: the probe answers in about a - // read instead of 45 or 90 seconds. Amb takes whichever speaks first and drops the other. + + // A caller-supplied override is already an authoritative point-in-time snapshot. if (sourcesOverride is not null) - return cached.Timeout(bound).Catch, TimeoutException>(ex => - Observable.Throw>(new TimeoutException( - $"Source snapshot for '{selfPath}' did not emit within {bound.TotalSeconds:0}s.", ex))); + return Observable.Return>(sourcesOverride); - return cached - .Amb(DirectSourceProbe(ntDef, selfPath)) + // 🚨 DIRECT READ FIRST — measured, not assumed. + // + // A compile needs a POINT-IN-TIME snapshot of its sources. It was taking that snapshot from + // the cached SYNCED query (NodeSources.GetSources → workspace.GetQuery), which exists to + // deliver LIVE updates — a guarantee a compile does not need and, on a large mesh, pays + // dearly for. Measured on memex 2026-07-27/28, same box, same data: + // + // the four discovery queries via IMeshService.Query ~0.25s (counts 16 / 4 / 1) + // the same discovery through the cached synced query 45.20s + // + // 45.20s is one SyncStreamOptions.HeartbeatInterval to within 200ms — the synced + // subscription misses its Initial and idles until the periodic heartbeat re-delivers. + // Everything else was ruled out by experiment first: the compile path itself is 0ms + // discovery on a fresh mesh, with ONE silo and with TWO (so not topology), and the queries + // themselves answer in a quarter second on memex (so not scale, ~90 schemas, or data + // volume). See issue #686 for the full elimination. + // + // So read directly and keep the synced query only as a FALLBACK for the case the direct + // read finds nothing — never the other way round. An earlier attempt (#682) kept the cache + // primary and raced a delayed probe against it; the probe never fired once in production, + // which is precisely the failure this ordering removes: the fast path is no longer + // conditional on losing a race. + return DirectSourceProbe(ntDef, selfPath, TimeSpan.Zero) + .Concat(Observable.Defer(() => ResolveSources(ntDef, selfPath, null).Take(1))) + .FirstAsync() .Timeout(bound) .Catch, TimeoutException>(ex => Observable.Throw>(new TimeoutException( $"Source snapshot for '{selfPath}' did not emit within {bound.TotalSeconds:0}s — " - + $"the shared synced source query ('{NodeSources.CacheId(selfPath)}') never produced " - + "its Initial (a lost/raced synced-query subscription, not a source-code error). " - + "The compile fails terminally instead of parking at Compiling forever; retry via " - + "the Compile button / a fresh RequestedReleaseAt.", ex))); + + "neither the direct mesh read nor the synced source query " + + $"('{NodeSources.CacheId(selfPath)}') produced a source set. The compile fails " + + "terminally instead of parking at Compiling forever; retry via the Compile " + + "button / a fresh RequestedReleaseAt.", ex))); } /// @@ -549,7 +558,7 @@ internal static ImmutableDictionary ApplyQueryChange( /// racing a primary, and it must never be the thing that fails a compile. /// private IObservable> DirectSourceProbe( - NodeTypeDefinition? ntDef, string selfPath) + NodeTypeDefinition? ntDef, string selfPath, TimeSpan? subscriptionDelay = null) { var queries = CodeQueryResolver .ExpandAll(ntDef?.Sources, CodeQueryResolver.DefaultSources, selfPath) @@ -589,15 +598,13 @@ private IObservable> DirectSourceProbe( .Where(merged => merged.Count > 0) .Select(merged => { - logger.LogWarning( - "Source discovery for '{SelfPath}' fell back to the UNCACHED probe after {Delay}s — " - + "the cached synced query stalled (a missed Initial idles until the {Heartbeat}s " - + "sync heartbeat). Recovered {Count} source node(s).", - selfPath, SourceStallProbeDelay.TotalSeconds, 45, merged.Count); + logger.LogDebug( + "Source discovery for '{SelfPath}': direct mesh read returned {Count} source node(s).", + selfPath, merged.Count); return (IEnumerable)merged; })) .Catch((Exception _) => Observable.Empty>()) - .DelaySubscription(SourceStallProbeDelay); + .DelaySubscription(subscriptionDelay ?? SourceStallProbeDelay); } ///