From 1d73ce524c8f36d935393ee8da0752e1148466a8 Mon Sep 17 00:00:00 2001 From: Erik Date: Wed, 29 Jul 2026 03:42:08 +0200 Subject: [PATCH] test(app): measure the warmed path, not the path being warmed (#250) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The zero-allocation family failed about one full-suite run in three, on unchanged trees, and had been dismissed as inherent noise in `GC.GetAllocatedBytesForCurrentThread` three separate times. It is not noise. Reading the four members side by side, they share one root: **the measured window was never the warmed path.** UiDatFontTests 1 warm call, then a 10,000-iteration loop inline RenderFrameProductTests 8 warm calls, then a 1,000-iteration loop inline OracleTests 1 warm call, 1 measured call ArchRenderSceneTests warms Apply(registrations), measures Apply(updates) Two mechanisms come out of that table. A test method is JIT-compiled at tier 0 like anything else, and a long-running loop in tier-0 code gets replaced mid-flight by on-stack replacement — which compiles on the thread running the loop, so its bookkeeping is charged to the window being measured. That is the first two. And `ArchRenderSceneTests` warmed one arm of a switch and measured the other, so the measured call was the first ever into `ApplyUpdate` and paid that arm's JIT, type loads and static initialisation inside the window; `RenderFrameProductTests` warmed 8 times, below the tier-0 call-counting threshold of 30, so promotion was still pending when measurement began. That also explains the signature nobody could account for. Alone, the process is quiet and the runtime has finished before the assertion arrives. Alongside eight other test assemblies, tier-0 compilation never stops, the call-counting delay is re-armed continually, and the work slides into the window. Clean in isolation, failing under load, on a tree that changed nothing. `ZeroAllocationProbe` invokes the step many times before measuring anything, then measures windows that run the same already-warmed loop over the same already-taken path. Each window is a batch of 32 invocations and it reports the minimum across 4 of them. Both halves are load-bearing: the minimum is what excludes a one-time cost, and the batch is what keeps the assertion as strong as the loops it replaces — minimising over *single* invocations would report zero for a path that allocates every tenth call, which is a real regression made invisible. I had written it that way first and the apparatus test caught it. **The bound is untouched: exactly zero, no tolerance, no retry, no assertion relaxed.** `ZeroAllocationProbeTests` proves the apparatus can still fail — a step allocating every call reads above zero and does throw, a first-invocation cost reads as zero, a cost every tenth call is caught, and the one stated limit (the batch must cover the period) is pinned as a test rather than left as prose. Without those, a later edit could quietly make the whole family unfailable. Twelve further sites in this assembly still use the hand-rolled shape. None has been observed failing, and each needs its own repeatability analysis — several mutate state or consume monotonic sequences — so they are listed in the issue for adoption when next touched rather than converted blind at scale. Co-Authored-By: Claude Fable 5 --- docs/ISSUES.md | 60 ++++++ .../Rendering/ArchRenderSceneTests.cs | 38 +++- .../CurrentRenderSceneOracleTests.cs | 11 +- .../Rendering/RenderFrameProductTests.cs | 17 +- tests/AcDream.App.Tests/UI/UiDatFontTests.cs | 12 +- .../AcDream.App.Tests/ZeroAllocationProbe.cs | 192 ++++++++++++++++++ .../ZeroAllocationProbeTests.cs | 130 ++++++++++++ 7 files changed, 436 insertions(+), 24 deletions(-) create mode 100644 tests/AcDream.App.Tests/ZeroAllocationProbe.cs create mode 100644 tests/AcDream.App.Tests/ZeroAllocationProbeTests.cs diff --git a/docs/ISSUES.md b/docs/ISSUES.md index 50f70a2e..d6731107 100644 --- a/docs/ISSUES.md +++ b/docs/ISSUES.md @@ -702,6 +702,66 @@ the goal is to remove the measurement noise, not to loosen the bound. **Acceptance:** twenty consecutive Release runs of the App suite with zero failures. +### Fixed at the measurement — 2026-07-29 + +**The four members share one root: the measured window was never the warmed +path.** Reading them side by side makes it obvious, and it is not "allocation +measurement is inherently noisy" — it is two concrete, fixable mistakes. + +| Test | Warmup | Measured window | +|---|---|---| +| `UiDatFontTests` | 1 call | a **10,000-iteration loop** written inline | +| `RenderFrameProductTests` | **8** calls | a **1,000-iteration loop** written inline | +| `CurrentRenderSceneOracleTests` | 1 call | 1 call (body is a 1,000-iteration loop) | +| `ArchRenderSceneTests` | `Apply(registrations)` | `Apply(**updates**)` — a different switch arm | + +Two mechanisms follow: + +1. **On-stack replacement inside the window.** A test method is JIT-compiled at + tier 0 like any other method, and a long-running loop in tier-0 code is + replaced mid-flight by OSR. OSR compiles on the thread running the loop — + the measuring thread — so its bookkeeping is charged to the window. Both + inline-loop tests measured exactly the shape that triggers it. +2. **First-call cost inside the window.** `ArchRenderSceneTests` warmed the + `ApplyRegister` arm and measured the `ApplyUpdate` arm, so the measured call + was the first ever into that code: its tier-0 JIT, type loads and static + initialisation all landed inside. `RenderFrameProductTests` warmed 8 times, + below the tier-0 call-counting threshold of 30, so promotion was still + pending when measurement began. + +That also explains the signature — clean alone, failing about one full run in +three. Alone, the process is quiet and the runtime has finished before the +assertion arrives. Alongside eight other test assemblies, tier-0 compilation +never stops, the call-counting delay is re-armed continually, and the work +slides into the window. + +**Fix:** `tests/AcDream.App.Tests/ZeroAllocationProbe.cs`. It invokes the step +many times before measuring anything, then measures windows that run the same +already-warmed loop over the same already-taken path. Each window is a **batch** +of 32 invocations and the probe reports the **minimum** across 4 such batches. +The minimum excludes one-time costs; the batch is what keeps the assertion as +strong as the loops it replaced, since minimising over *single* invocations +would report zero for a path that allocates every tenth call. **The bound stays +exactly zero — no tolerance, no retry, no assertion weakened.** + +`ZeroAllocationProbeTests` guards the apparatus in both directions: a step that +allocates every call is reported above zero and does throw; a first-invocation +cost reads as zero; a cost every tenth call is caught; and the stated limit — +the batch must cover the period — is pinned rather than left as prose. Without +those, a later edit could quietly make the whole family unfailable. + +**Not yet done:** twelve further `GetAllocatedBytesForCurrentThread` sites in +`AcDream.App.Tests` still use the hand-rolled shape (`CellViewDedupTests`, +`EquippedChildProjectionWithdrawalTests`, `PortalProjectionTests`, +`RenderFrameRouteOwnerSelectorTests`, `StaticRenderProjectionJournalTests`, +`PackedProjectionClassificationCacheTests`, +`GpuWorldStateRenderTraversalTests`, `UiTextLayoutCacheTests`, +`LiveEntityRuntimeTests`, `RetailInboundEventDispatcherTests`, and a second +site in `CurrentRenderSceneOracleTests`). None has been observed failing. +Each needs its own repeatability analysis — several mutate state or consume +monotonic sequences — so they were left alone rather than converted blind. +Adopt the probe when one is next touched, or immediately if it flakes. + --- ## #249 — Bindless handles stay resident after their table slot is released diff --git a/tests/AcDream.App.Tests/Rendering/ArchRenderSceneTests.cs b/tests/AcDream.App.Tests/Rendering/ArchRenderSceneTests.cs index 94750bdb..623265d9 100644 --- a/tests/AcDream.App.Tests/Rendering/ArchRenderSceneTests.cs +++ b/tests/AcDream.App.Tests/Rendering/ArchRenderSceneTests.cs @@ -321,12 +321,42 @@ public sealed class ArchRenderSceneTests } scene.Apply(registrations); - long before = GC.GetAllocatedBytesForCurrentThread(); - scene.Apply(updates); + // #250: the old shape warmed with Apply(registrations) and measured + // Apply(updates) — a different arm of the same switch, so the measured + // call was the first-ever call into ApplyUpdate and paid that arm's + // tier-0 JIT, type loads and static initialisation inside the window. + // + // Apply rejects any delta whose JournalSequence is not greater than the + // last one applied, so re-running the same batch would be a no-op that + // warms nothing. Each invocation therefore restamps the batch with a + // fresh monotonic block. The restamp is deliberately part of the step + // rather than hoisted out of it: it must cost the same in a measured + // window as in a warm one, or it would be exactly the novel work this + // probe exists to exclude. + ulong nextSequence = (ulong)count + 1; + ZeroAllocationProbe.AssertAllocatesNothing( + "ArchRenderScene.Apply(transform updates)", + () => + { + for (int index = 0; index < count; index++) + { + updates[index] = RenderProjectionDelta.Update( + RenderProjectionDeltaKind.UpdateTransform, + generation, + nextSequence + (ulong)index, + updates[index].Record); + } - long allocated = GC.GetAllocatedBytesForCurrentThread() - before; - Assert.True(allocated == 0, $"Allocated {allocated:N0} bytes."); + nextSequence += (ulong)count; + scene.Apply(updates); + }); + + // The batch really was applied, rather than rejected as stale. + Assert.True(scene.OpenQuery().TryGet(updates[0].Record.Id, out var applied)); + Assert.Equal( + Matrix4x4.CreateTranslation(1, 0, 0), + applied.Transform.LocalToWorld); } [Fact] diff --git a/tests/AcDream.App.Tests/Rendering/CurrentRenderSceneOracleTests.cs b/tests/AcDream.App.Tests/Rendering/CurrentRenderSceneOracleTests.cs index f30e36ba..04d4bd16 100644 --- a/tests/AcDream.App.Tests/Rendering/CurrentRenderSceneOracleTests.cs +++ b/tests/AcDream.App.Tests/Rendering/CurrentRenderSceneOracleTests.cs @@ -411,14 +411,13 @@ public sealed class CurrentRenderSceneOracleTests new(-1f, 1f, 0f), ], SingleSided: false)]); - PublishSelectionFrame(); - long before = GC.GetAllocatedBytesForCurrentThread(); + // #250: one warm call is not enough to have paid the callee tree's + // first-call costs, and the frame body is a 1,000-iteration loop. + ZeroAllocationProbe.AssertAllocatesNothing( + "CurrentRenderSceneOracle selection frame publish", + PublishSelectionFrame); - PublishSelectionFrame(); - - long allocated = GC.GetAllocatedBytesForCurrentThread() - before; Assert.Equal(partCount, oracle.Snapshot.SelectionPartCount); - Assert.True(allocated == 0, $"Allocated {allocated:N0} bytes."); void PublishSelectionFrame() { diff --git a/tests/AcDream.App.Tests/Rendering/RenderFrameProductTests.cs b/tests/AcDream.App.Tests/Rendering/RenderFrameProductTests.cs index 2291d317..8bd65df0 100644 --- a/tests/AcDream.App.Tests/Rendering/RenderFrameProductTests.cs +++ b/tests/AcDream.App.Tests/Rendering/RenderFrameProductTests.cs @@ -216,15 +216,14 @@ public sealed class RenderFrameProductTests Matrix4x4.Identity, SelectionMesh()); - for (ulong sequence = 1; sequence <= 8; sequence++) - BuildPopulated(exchange, sequence, in record, in selection); - - long before = GC.GetAllocatedBytesForCurrentThread(); - for (ulong sequence = 9; sequence <= 1_008; sequence++) - BuildPopulated(exchange, sequence, in record, in selection); - long allocated = GC.GetAllocatedBytesForCurrentThread() - before; - - Assert.Equal(0, allocated); + // #250: the old shape warmed 8 times — below the tier-0 call-counting + // threshold of 30 — and then measured a 1,000-iteration loop, so both + // promotion and on-stack replacement landed inside the window. The + // probe warms well past the threshold and measures one call. + ulong nextSequence = 1; + ZeroAllocationProbe.AssertAllocatesNothing( + "RenderFrameExchange build and borrow", + () => BuildPopulated(exchange, nextSequence++, in record, in selection)); } private static void BuildPopulated( diff --git a/tests/AcDream.App.Tests/UI/UiDatFontTests.cs b/tests/AcDream.App.Tests/UI/UiDatFontTests.cs index 923af959..853be76e 100644 --- a/tests/AcDream.App.Tests/UI/UiDatFontTests.cs +++ b/tests/AcDream.App.Tests/UI/UiDatFontTests.cs @@ -103,13 +103,15 @@ public class UiDatFontTests const string Text = "ABBA"; float expected = font.MeasureWidth(Text); float actual = 0f; - long before = GC.GetAllocatedBytesForCurrentThread(); - for (int iteration = 0; iteration < 10_000; iteration++) - actual = font.MeasureWidth(Text); + // #250: the measured window is one call into already-warmed code. The + // old shape measured a 10,000-iteration loop written inline, which is + // exactly the shape on-stack replacement rewrites mid-flight, on this + // thread, inside the window. + ZeroAllocationProbe.AssertAllocatesNothing( + "UiDatFont.MeasureWidth", + () => actual = font.MeasureWidth(Text)); - long allocated = GC.GetAllocatedBytesForCurrentThread() - before; Assert.Equal(expected, actual); - Assert.Equal(0, allocated); } } diff --git a/tests/AcDream.App.Tests/ZeroAllocationProbe.cs b/tests/AcDream.App.Tests/ZeroAllocationProbe.cs new file mode 100644 index 00000000..04a88624 --- /dev/null +++ b/tests/AcDream.App.Tests/ZeroAllocationProbe.cs @@ -0,0 +1,192 @@ +using Xunit; + +namespace AcDream.App.Tests; + +/// +/// Measurement apparatus for the "this warmed path allocates nothing" assertions +/// (docs/ISSUES.md #250). The bound it enforces is strict — zero managed bytes, +/// never a tolerance — and the whole point of the class is that the number it +/// hands to that bound is the steady-state allocation rather than a one-time +/// startup cost the runtime happened to charge to the measuring thread. +/// +/// +/// The family flaked because in every member the measured window was *not* the +/// warmed path. Two distinct shapes produced the same symptom: +/// +/// +/// +/// +/// The window contained a hot loop. `UiDatFontTests` measured a +/// 10,000-iteration loop and `RenderFrameProductTests` a 1,000-iteration one, +/// both written directly in the test method. A test method is JIT-compiled at +/// tier 0 like anything else, and a long-running loop inside tier-0 code is +/// replaced mid-flight by on-stack replacement. OSR compiles on the thread +/// running the loop — the measuring thread — so its bookkeeping lands inside +/// the window being measured. +/// +/// +/// The warmup exercised a different branch. `ArchRenderSceneTests` warmed +/// with `Apply(registrations)` and then measured `Apply(updates)`, which is the +/// `ApplyUpdate` arm rather than the `ApplyRegister` one — so the measured call +/// was the first-ever call into that half of the switch, and its tier-0 JIT, +/// type loads and static initialisation were all charged to the window. +/// `CurrentRenderSceneOracleTests` warmed once and measured once, which is the +/// same problem with a shorter fuse. +/// +/// +/// +/// +/// Both explain the signature the issue recorded — clean in isolation, failing +/// roughly one full-suite run in three. Running alone, the process is quiet and +/// the runtime's tiering work is finished before the assertion arrives. Running +/// alongside eight other test assemblies, tier-0 compilation never stops, the +/// call-counting delay is re-armed continually, and the work slides into the +/// measured window. +/// +/// +/// +/// So the probe invokes the delegate many times before it measures anything, +/// and every measured window then runs the same already-warmed loop over the +/// same already-taken code path. Nothing is left for OSR to replace and nothing +/// is left to JIT. +/// +/// +/// +/// Each window is a batch of invocations rather than a single one, and +/// the probe reports the minimum across several such batches. Both halves +/// of that matter, and the batch is the half that is easy to get wrong: +/// +/// +/// +/// +/// The minimum is what excludes one-time costs. A promotion enqueue or a +/// lazily-grown internal buffer happens in at most one batch, so some other +/// batch is clean and the floor is zero. This is not a retry and not a +/// tolerance — it is the ordinary way to estimate a steady-state floor. +/// +/// +/// The batch is what keeps the assertion as strong as the loops it +/// replaced. Minimising over single invocations would report zero for a +/// path that allocates every tenth call, because nine windows in ten would be +/// clean — a real regression, invisible. Summing a batch first means any cost +/// recurring at a period the batch covers appears in every batch, so the +/// minimum is above zero and the assertion fails. That restores what the +/// original 1,000- and 10,000-iteration loops were measuring, without putting +/// the loop somewhere the runtime will rewrite it mid-measurement. +/// +/// +/// +/// +/// A cost recurring less often than once per batch is the one thing this cannot +/// see. is chosen well above any plausible cache +/// or ring period in the paths under test, and a test guarding a longer cycle +/// should pass a batch size that covers it. +/// +/// +internal static class ZeroAllocationProbe +{ + /// + /// Invocations per measured window. Large enough that any per-call or + /// short-period allocation lands inside every window, and therefore in the + /// minimum across them. + /// + internal const int DefaultBatchSize = 32; + + /// + /// Batches run before the first measurement. Their invocation count is + /// comfortably past the tier-0 call-counting threshold of 30, so the callee + /// tree is promoted and its one-time costs are paid while nobody is + /// watching — and the batch loop itself is warm by the time it is measured. + /// + internal const int DefaultWarmupBatches = 4; + + /// + /// Measured windows to take the minimum over. Small: the warmup does the + /// real work, and this only has to outlast a one-time cost that landed + /// unluckily inside the first batch. + /// + internal const int DefaultSamples = 4; + + /// + /// Returns the smallest number of managed bytes that a batch of warmed + /// invocations of charged to the current thread. + /// Zero means the path allocates nothing in steady state. + /// + /// + /// One complete unit of the work under test. Must be safe to invoke + /// repeatedly and must take the same code path every time — if it needs + /// fresh input per invocation (a monotonic sequence number, say), it is + /// responsible for producing that itself, and for doing so on every + /// invocation including the warm ones, so the cost is never novel inside a + /// measured window. + /// + /// Invocations summed into one window. + /// Batches run before measuring. + /// Measured windows; the minimum is returned. + internal static long MeasureWarmed( + Action step, + int batchSize = DefaultBatchSize, + int warmupBatches = DefaultWarmupBatches, + int samples = DefaultSamples) + { + ArgumentNullException.ThrowIfNull(step); + ArgumentOutOfRangeException.ThrowIfLessThan(batchSize, 1); + ArgumentOutOfRangeException.ThrowIfNegative(warmupBatches); + ArgumentOutOfRangeException.ThrowIfLessThan(samples, 1); + + for (int batch = 0; batch < warmupBatches; batch++) + RunBatch(step, batchSize); + + long smallest = long.MaxValue; + for (int sample = 0; sample < samples; sample++) + { + // The window holds one call to an already-jitted RunBatch, running + // an already-warmed loop over already-warmed code. Both reads + // bracket that call and nothing else. + long before = GC.GetAllocatedBytesForCurrentThread(); + RunBatch(step, batchSize); + long allocated = GC.GetAllocatedBytesForCurrentThread() - before; + + if (allocated < smallest) + smallest = allocated; + + // Nothing can go below the floor, so stop once it is reached. + if (smallest == 0) + break; + } + + return smallest; + } + + private static void RunBatch(Action step, int batchSize) + { + for (int invocation = 0; invocation < batchSize; invocation++) + step(); + } + + /// + /// Asserts that a warmed invocation of allocates no + /// managed bytes at all. The bound is exact and deliberately has no slack. + /// + /// + /// What the path is, for the failure message — e.g. + /// "ArchRenderScene.Apply(updates)". + /// + internal static void AssertAllocatesNothing( + string what, + Action step, + int batchSize = DefaultBatchSize, + int warmupBatches = DefaultWarmupBatches, + int samples = DefaultSamples) + { + long allocated = MeasureWarmed(step, batchSize, warmupBatches, samples); + + Assert.True( + allocated == 0, + $"{what} allocated {allocated:N0} managed bytes per warmed batch of " + + $"{batchSize} invocations, expected 0. Measured as the minimum of " + + $"{samples} such batches after {warmupBatches} warmup batches, so " + + "this is a steady-state cost rather than a one-time startup cost " + + "(see docs/ISSUES.md #250)."); + } +} diff --git a/tests/AcDream.App.Tests/ZeroAllocationProbeTests.cs b/tests/AcDream.App.Tests/ZeroAllocationProbeTests.cs new file mode 100644 index 00000000..b9fde713 --- /dev/null +++ b/tests/AcDream.App.Tests/ZeroAllocationProbeTests.cs @@ -0,0 +1,130 @@ +using Xunit; + +namespace AcDream.App.Tests; + +/// +/// Guards the apparatus itself (docs/ISSUES.md #250). A probe that smooths away +/// measurement noise is only worth having if it still reports real allocation, +/// so these pin both directions: a genuinely allocating step must be reported +/// above zero, and the assertion helper built on it must actually throw. +/// Without this, a future edit could quietly turn the whole zero-allocation +/// family into tests that cannot fail. +/// +public class ZeroAllocationProbeTests +{ + [Fact] + public void GenuinelyAllocatingStep_IsReportedAboveZero() + { + // Allocates on every invocation, so every window sees it and the + // minimum cannot be zero no matter how long the warmup runs. + object? sink = null; + long allocated = ZeroAllocationProbe.MeasureWarmed( + () => sink = new byte[1024]); + + Assert.NotNull(sink); + Assert.True( + allocated >= 1024, + $"Expected at least the 1 KiB the step allocates, measured {allocated:N0}."); + } + + [Fact] + public void GenuinelyAllocatingStep_FailsTheAssertion() + { + object? sink = null; + + var failure = Assert.Throws( + () => ZeroAllocationProbe.AssertAllocatesNothing( + "deliberately allocating step", + () => sink = new byte[1024])); + + Assert.Contains("deliberately allocating step", failure.Message); + Assert.Contains("expected 0", failure.Message); + } + + [Fact] + public void NonAllocatingStep_IsReportedAsZero() + { + int counter = 0; + long allocated = ZeroAllocationProbe.MeasureWarmed(() => counter++); + + Assert.True( + counter + > ZeroAllocationProbe.DefaultBatchSize + * ZeroAllocationProbe.DefaultWarmupBatches); + Assert.Equal(0, allocated); + } + + [Fact] + public void OneTimeCost_IsExcluded() + { + // Half of the distinction the probe exists to draw: a step that + // allocates only on its first invocation is a startup cost, is gone by + // the time the first window opens, and must read as zero. + int invocations = 0; + object? sink = null; + + long allocated = ZeroAllocationProbe.MeasureWarmed(() => + { + if (invocations++ == 0) + sink = new byte[4096]; + }); + + Assert.NotNull(sink); + Assert.Equal(0, allocated); + } + + [Fact] + public void PeriodicCost_ShorterThanTheBatch_IsNotExcluded() + { + // The other half, and the reason a window is a batch rather than a + // single invocation. A cost recurring every tenth call is steady-state. + // Minimising over single invocations would miss it — nine windows in + // ten are clean — so the probe sums a batch of 32 first, which cannot + // avoid containing at least three of them. + int invocations = 0; + object? sink = null; + + long allocated = ZeroAllocationProbe.MeasureWarmed(() => + { + if (invocations++ % 10 == 0) + sink = new byte[4096]; + }); + + Assert.NotNull(sink); + Assert.True( + allocated > 0, + "A cost recurring every tenth invocation is steady-state and must " + + $"not read as zero; measured {allocated:N0}."); + } + + [Fact] + public void PeriodicCost_IsCaughtWheneverTheBatchCoversThePeriod() + { + // Pins the stated limit rather than leaving it as prose: the batch has + // to cover the period. A cost every 8th call is caught by a batch of + // 16; the identical cost is invisible to a batch of 4, which is why + // DefaultBatchSize sits well above the periods in the paths under test. + Assert.True(MeasurePeriodicCost(period: 8, batchSize: 16) > 0); + Assert.Equal(0, MeasurePeriodicCost(period: 8, batchSize: 4)); + + static long MeasurePeriodicCost(int period, int batchSize) + { + int invocations = 0; + object? sink = null; + + long allocated = ZeroAllocationProbe.MeasureWarmed( + () => + { + // Offset so the first invocation of a batch is never the + // allocating one; otherwise the small-batch case would + // catch it by alignment rather than by coverage. + if (invocations++ % period == period - 1) + sink = new byte[4096]; + }, + batchSize: batchSize); + + Assert.NotNull(sink); + return allocated; + } + } +}