fix #429: allocation-free shadow topology rebuild + churn-frame pipelining

The directional-shadow topology rebuilt on every streaming-churn frame
and was the measured body of the run-hitch stalls (701 of 708 baseline
stalls alloc-correlated):

- The draw sort comparer's enum-vs-enum CompareTo bound to
  Enum.CompareTo(object) and boxed BOTH operands on every comparison —
  a constant ~38.9 MB of garbage per topology rebuild (~4M boxes),
  handing the GC a forced gen0 collection mid-frame. The full ~100k-draw
  sort is replaced outright: draws hash-group by exact DrawKey in one
  O(n) pass over retained chained-index arrays, and only the
  few-thousand DISTINCT group keys sort (order-preserving packed
  material|cull|firstIndex|baseVertex + count|slot|layer|foliage keys,
  first-appearance tie-break) — bit-identical emission order to the old
  stable sort, near-zero allocation, and no per-draw comparisons at all.
- The caster frame sorts 4-byte indices keyed on SortKey.Value instead
  of shuffling multi-hundred-byte records through a boxing comparer.
- Owner-approved pipelining: on a frame whose shadow inputs just changed
  (the same frame already paying frame-view/landscape rebuilds), the
  caster-frame and prepared-draws topology rebuilds defer to the next
  quieter frame, capped at two consecutive deferrals — inside the GPU
  fence depth, so retained draws never reference a released arena range.
  First build, generation change, caster BuildSequence change, and
  journal overflow force the immediate path; deferred refreshes skip
  identity-mismatched journal rows.

Owner-accepted in both presentation modes: stall frames 5.8/s -> ~0.45/s
uncapped (0.49/s capped), median stall 20.3 -> 13.7 ms, >25 ms frames
near zero, 275 fps uncapped baseline restored. Allocation gate: a warmed
topology rebuild must allocate <2 KiB (DirectionalShadowPreparedDrawTests).
docs/ISSUES.md carries the full evidence trail; the residual
content-proportional rebuild milliseconds are filed as the
incremental-topology successor, and the pre-existing town-view scaling
latch is filed as #432.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Erik 2026-08-24 09:16:58 +02:00
parent 4873c10673
commit ad69558908
6 changed files with 652 additions and 69 deletions

View file

@ -177,6 +177,272 @@ pipeline):**
The pack-ON player-jump phase question remains as the second defect but
becomes mostly moot once the stalls themselves shrink.
**SITE ATTRIBUTION CORRECTED + FIXED 2026-08-23 (implementation session).**
The frame-history correlation (701/708 stall frames at 30-77 MB) was right;
the SITE was wrong. The baseline CSV's own stage columns refute the
mesh-completion theory: in all 701 alloc-correlated stall frames
`upload_us` is ~3 µs — `WbMeshAdapter.Tick` (which contains the entire
`UploadGfxObjMeshData` completion drain AND the mip flush, inside the
tracked Upload stage) did essentially nothing in those frames. A temporary
per-phase allocation probe (`GC.GetAllocatedBytesForCurrentThread` marks
through the render frame, driven by an automated Holtburg running route)
attributed the allocation exactly:
- **THE stall allocator: `DirectionalShadowPreparedDraws.Complete`'s
`Array.Sort` comparer** (`WbDrawDispatcher.DirectionalShadows.cs`).
`x.Material.CompareTo(y.Material)` / `x.CullMode.CompareTo(y.CullMode)`
bind to `Enum.CompareTo(object)`, which boxes BOTH operands on every
comparison — measured at a constant **38.88 MB per directional-shadow
topology rebuild** (~4M boxes across the N·log N sort of every prepared
caster draw in the resident window). The topology rebuilds whenever
`RenderDataAvailabilityVersion` moves — i.e. on every streaming-churn
frame while the player runs (the Atmospheric pack's shadow prepass is the
consumer, matching pack-ON visibility; sustained churn windows rebuilt
260 consecutive frames ≈ 10 GB of garbage in seconds). Everything else
in the rebuild (caster copy, classification loop, grouping) measured
~0.3 MB — the shadow stack's retained-scratch design was already sound;
two enum comparisons were the whole leak.
- Secondary (the original theory, real but ~7 of 708 baseline frames):
the `UploadGfxObjMeshData` LINQ conversion, 8-14 MB on completion
frames.
- Also observed while probing, pre-existing and bounded, NOT #429:
composite-texture warmup (`TickCompositeTextureCache`, 16/frame budget)
and PView reveal churn allocate ~4-30 MB on teleport/reveal frames.
**Fix landed (pending owner gate):**
1. The sort comparer compares enums through their underlying integers —
allocation-free, identical ordering. Verified live: the 38.88 MB
rebuild signature is gone (big-alloc frames on the automated running
route: 124 → ~0 shadow-rebuild frames; only the pre-existing
composite/pview/reveal allocations remain).
2. The handoff's de-LINQ of `UploadGfxObjMeshData`: one exact-size
retained `CPUIndices` array now feeds both the pick copies and the
arena upload (`GlobalMeshBuffer.UploadMesh` takes (offset, count)
segments of it); `CPUPositions` fills by direct loop; the
`Sum`/`Any`/`FirstOrDefault` transients are gone. Behavior-preserving:
same bytes staged, same batch order, same retained content.
3. Two I1-style allocation gates: a warmed directional-shadow topology
rebuild must allocate < 2 KB
(`DirectionalShadowPreparedDrawTests.AWarmedTopologyRebuildAllocatesNearZero`),
and a warmed mesh completion must allocate near its retained-copy size
(`MeshPipelineDeviceSeamTests.AWarmedMeshCompletionAllocatesNearItsRetainedCopySize`).
4. The temporary `PlayerPresentationProbe` and the attribution probe are
stripped.
Session note: one automated probe run (of seven) exited with
0xC0000374 (STATUS_HEAP_CORRUPTION) during graceful close AFTER the route
completed, on a diagnostic build; not reproduced since. Watch for it in
future gate runs.
Remaining owed: the owner's two-sided acceptance (feel gate + the ~45 s
pack-ON measured run against `artifacts/owner-gate/frame-history-429.csv`).
The pack frame-graph ordering question (defect 2) stays deferred unless
residual hitches survive.
**OWNER GATE ROUND 1 (2026-08-23, same evening): allocation half PASSED,
felt hitch PERSISTS — residual attributed and a second fix round landed.**
The owner's ~45 s pack-ON drive on the fixed build: alloc-correlated stalls
701 → 5, stall-frame allocation median 39.6 MB → 40 KB, GC pressure gone —
but the micro-freeze feel remained. A time-triggered probe round (print any
frame > 12 ms with per-phase attribution) on an owner-driven clean run
measured the residual exactly: **82 stalls in 47 s (1.75/s — the ORIGINAL
pre-investigation stall rate), median 19.1 ms, clusters every ~1.3-2 s**,
near-zero allocation. Composition per stall frame — a rebuild CASCADE all
triggered by one `RenderDataAvailabilityVersion` bump (streaming publish)
and all paid in the SAME frame:
- `pk:casters` 3.5-14 ms — `DirectionalShadowCasterFrame.Build` copies +
classifies every outdoor projection record;
- `wb:sd-topo` 4-28 ms — `DirectionalShadowPreparedDraws.Complete`
(sort + group), allocation-free after the boxing fix but still the CPU;
- `ws:pview` 4-12 ms — the world draw path's own version-keyed work,
elevated on the same frames.
The owner's "introduced with the night-sky change" hypothesis was tested
directly and REFUTED: the sky default-script segment (`b:skypes`) crossed
1 ms once (2.3 ms) in the whole run. Timing note: the VisualMaster
directional-shadow machinery landed immediately before the night-sky
session where the hitch was first noticed — the sky was the nearest
visible change, the shadow prepass the actual newcomer.
**Second fix round (in tree, uncommitted): packed-key index sorts.** Both
hot sorts — `DirectionalShadowPreparedDraws.Complete`'s draw sort and
`DirectionalShadowCasterFrame.Build`'s caster sort — previously moved
multi-hundred-byte records through interface comparers. Both now sort
4-byte index arrays against one 64-bit key (draw sort: an order-preserving
packed prefix Material|CullMode|FirstIndex|BaseVertex with exact-comparer
tie-break; caster sort: the traversal `SortKey.Value` directly), then
permute once through retained scratch. Total order preserved everywhere
the arena can reach; 131 directional-shadow tests including both #429
allocation gates pass. Owner re-drive pending at time of writing.
**Measurement hygiene note:** an A/B (same launch recipe, same position,
with/without `ACDREAM_UI_PROBE_SCRIPT`, and with an idle one-command
script) proved the harness launch recipe and the script runner are BOTH
innocent of the #432 low-FPS mode — both idle arms run 4.5 ms/17 KB
frames. The mode requires the synthetic route's PATH (through the town
view); owner-driven runs avoid it naturally.
**OVERNIGHT ROUNDS 2-4 (2026-08-23→24): rebuild cascade cheapened but the
felt hitch is defect 2, now MEASURED as camera/player decoherence.**
Owner drives 2-4 each reported the hitch "unchanged" while every attacked
piece shrank (caster copy+classify+sort ≈ 1.3-2 ms each; the draw sort
round-1 index sort actually REGRESSED — instanced duplicates share one
packed key, so the tie-break full-record comparer became the hot path,
6.5 → 14.6 ms avg, caught by the owner's drive-2 data — round-2 replaced
the 100k-draw sort entirely with O(n) hash-grouping over retained chained
arrays plus an O(g log g) sort of the ~few-thousand DISTINCT group keys;
same emitted product, deterministic). Post-everything, owner-terrain stalls
still ~2.1/s at 27-31 ms median: per-frame `pv:frameview` (scene
frame-view build) + `pv:landscape` + the residual topo loop dominate.
Micro-shaving converges too slowly to clear 12 ms — the FEEL lever is
defect 2.
**Defect 2 objectively measured** (from the ORIGINAL owner captures
`player-present-429-packON/-packoff.csv`, camera-relative analysis):
pack ON, 50 of 85 long moving frames separate the presented player from
the camera by ~1 m in one frame (18x the normal 5.5 cm relative step);
pack OFF, 7 of 83 at half the size. The felt hitch IS this one-frame
camera/player decoherence — the player lurches on screen while the
camera-anchored world stays smooth.
**MECHANISM LOCATED (2026-08-24 ~00:10, per-update
`ACDREAM_PROBE_CAMERA_TICK` capture, pack ON, running 16 m/s):** on
long (~27 ms) updates, HALF the samples advance the presented player only
~12-16 cm (a third of elapsed time) while the chase camera steps the full
~40 cm; the other half advance both coherently (~42-53 cm each). The two
run on DIFFERENT clocks: the presented player position is
`ComputeRenderPosition` = lerp(prevQuantum, currQuantum,
pending/MinQuantum) on the retail 30 Hz OBJECT CLOCK (alpha CLAMPS at 1 —
near-quantum-length updates alias against the 33.3 ms quantum and the
presented position under-advances or freezes), while the camera's damping
(`ComputeDampingAlpha(stiffness, dt)` in RetailChaseCamera/ChaseCamera)
integrates WALL-CLOCK dt — on a 27 ms update it closes ~half its
accumulated ~1 m chase lag regardless of the target having barely moved.
Camera and player cross → the lurch. High-FPS updates (pack OFF, ~4 ms)
glide through the quanta, which is why OFF feels smooth with the same
stall count — and why shrinking the stalls below ~quantum length would
also mask it, but the CLOCK MISMATCH is the root cause.
**DEFECT-2 FIX IMPLEMENTED + MEASURED (2026-08-24 ~00:20, in tree,
uncommitted).** `PlayerMovementController.PresentedDeltaSeconds` now
reports how far the presented position's own clock advanced each tick
(quanta simulated x MinQuantum + clamped-pending delta; wall dt on a
Discarded/teleport batch so the camera snaps along), and
`CameraFrameController` integrates the chase-camera damping with THAT
delta instead of wall dt (manual zoom/pitch stays on wall dt — an input
rate, not target chasing). This RESTORES retail's semantics — the camera
updates on the physics clock via PlayerPhysicsUpdatedCallback
(0x00452d60) — so no divergence-register row: it retires an unregistered
wall-clock deviation. Verified on the automated route, pack ON:
- per long update (28-38 ms): cam/player step ratio 0.75-1.19 (was
2.6-3.4x with ~27 cm crossing); |cam-player| med 2.2 cm, p90 7 cm,
max 16.7 cm (~12x tighter);
- per frame: typical camera-relative player step 5.5 cm → 0.3 cm; the
baseline's 50-of-85 ~1 m long-frame lurches → 3 frames above 25 cm
(max 31 cm) — better than the old pack-OFF arm the owner perceived as
smooth.
Runtime suite 1,818/0, hermetic App suite 6,082/0.
**FEEL GATE ROUNDS 2-3 + THE FINAL TWO FIXES (2026-08-24 00:20-01:10).**
Round 2 ("still there") caught that the camera-clock fix alone leaves a
coherent whole-view freeze: with camera and player now in lockstep, the
remaining artifact was the presented position itself under-advancing.
Root cause: `ComputeRenderPosition` normalized its lerp by the FIXED
MinQuantum while the retail clock simulates VARIABLE-length quanta
(everything above MinQuantum in one step, split at MaxQuantum=0.2 s) — a
long host frame fired a >33 ms quantum, alpha reset across the bigger
gap, and presentation froze then replayed fast. Fixed by normalizing by
the actual last-quantum interval (`_lastQuantumSeconds`), with
`PresentedDeltaSeconds` accounting continuous presented time (the camera
consumes the same delta, so both stay coherent by construction). Two
Runtime tests that pinned the old fixed-quantum lerp were updated to the
continuous-rate contract (Update_SubQuantumFrame_...,
Update_LeftoverAboveMinQuantum_... — renamed
...InterpolatesAcrossTheActualQuantumInterval).
Round 3 landed the owner-approved (A) **shadow rebuild pipelining**: on a
frame where the shadow inputs just changed (streaming churn — the same
frame already pays the frame-view/landscape rebuilds), the caster and
prepared-draws topology rebuilds defer to the next quieter frame, capped
at 2 consecutive deferrals (inside the GPU fence depth, so retained draws
can never reference a released-and-reused arena range). Deferral is
best-effort with hard safety rails: first build, generation change,
transform-journal overflow, and any caster rebuild force the full path
immediately; stale-topology refreshes skip identity-mismatched journal
rows instead of throwing. Implemented across
`DirectionalShadowCasterFrame.Build(allowTopologyRebuild)`,
`WbDrawDispatcher.PrepareDirectionalShadowDraws(allowTopologyRebuild)`,
and the policy in `AtmosphericPostProcessGraph.RenderDirectionalShadows`.
**Measured outcome (owner feel gate 3, ~210 s drive incl. pack
switching): median stall 20.3 → 13.7 ms; automated route: med 13.9 ms
(was 27-31), max 33, frames >16 ms at 1.4/s. Owner verdict: "almost
gone."** Residual composition (deep marks): frame-view build ~4.7 ms +
early landscape slices ~3.9 ms per churn frame, plus the pipelined shadow
rebuild ~8 ms on its own frame — content-proportional work with no
pathological defect left; further reduction is the incremental-topology
campaign already described above. OWED: the owner's final morning
confirmation, then strip the probe families (RenderFrameAllocProbe +
marks incl. fv:/pl:, PlayerPresentationProbe, CameraTickProbe) and
commit on request.
**Tree state at pause (uncommitted, on the worktree branch):** four landed
optimizations (enum-boxing comparer fix, upload de-LINQ + arena segment
API, caster-frame index sort, draw hash-grouping) + two allocation-gate
tests; TEMPORARY apparatus still wired: `RenderFrameAllocProbe` (env
`ACDREAM_PROBE_FRAME_ALLOC`, time-or-alloc triggered, 4/s print sampling)
with ~30 phase marks, `PlayerPresentationProbe`
(`ACDREAM_PROBE_PLAYER_PRESENT`), `CameraTickProbe`
(`ACDREAM_PROBE_CAMERA_TICK`). All env-gated, off by default; strip all
three families with the defect-2 fix. Hermetic App suite 6,082/0 (one
transient parallel-load flake observed once, known-flake class).
---
## #432 — Sustained ~6.3 MB/frame + ~20 ms/frame while Holtburg town center is in view
**Status:** OPEN
**Severity:** MEDIUM (halves frame rate and allocates ~300 MB/s while it holds)
**Filed:** 2026-08-23 (found while measuring the #429 fix; NOT caused by it —
reproduces identically on the pre-fix binary)
**Component:** rendering (untracked render path — attribution not yet done)
**Symptom:** with the player at/near Holtburg town center (observed at cell
`0xA9B40019`; NOT at `0xA9B40036` a few cells away), every frame allocates a
near-constant ~6.3 MB and costs ~20 ms CPU (~45-50 FPS from a ~270 FPS
baseline), indefinitely, with Gen0 at ~6/s. `update_us` ~1.8 ms and
`upload_us` ~0 — the time and allocation sit in the untracked render path
(same measurement seam as #429). The mode begins the frame the view reaches
the spot (after a `/teleloc` there, or immediately at login when parked
there) and held for 80+ s of continuous running in a loop around town.
**Evidence:** frame-history CSVs + stdout under the 2026-08-23 session
scratchpad (`frame-history-postfix-224749.csv` — healthy 7 ms/20 KB frames
for 20 s until the teleport, then 6.1-6.3 MB/frame for the rest;
`frame-history-postfix-225154.csv` — the mode active from login onward;
`probe-429-223228.out.log` — the SAME tail on the PRE-#429-fix binary).
The #429 owner baseline (spawn `0xA8B4002A`, running loops near-but-not-in
town) never shows it: normal frames ~22 KB at ~247 FPS.
**Partial attribution + latch behavior (from the #429 probe runs):** the
per-phase lines that crossed the probe's 8 MB print floor split the mode as
a near-constant **~6.0 MB/frame in the PView draw
(`WorldSceneRenderer``DrawInside`)** plus an intermittent ~4.26 MB in
the post-world diagnostics phase. Once triggered it LATCHES: a 70 s
straight-line run ~300+ m away from town held EXACTLY ~6,187 KB/frame the
whole way (the town stays inside the Near ring at that distance, so
whatever content drives it stays resident). Trigger observed at town
center `0xA9B40019` but NOT at `0xA9B40036`, and NOT on the owner's
`0xA8B4002A`-spawn loops. Candidate families, unverified: the town's
buildings entering the PView nearby-building/cell set; an animated static
(the windmill, #426-adjacent) keeping a per-frame path hot. Re-add the
#429 attribution probe (one level deeper, inside DrawInside) and measure —
do NOT guess.
**Gate caution:** a post-#429 measurement run that strays into this latch
shows every frame as a ~20 ms "stall" at ~6.3 MB — that is THIS issue, not
#429 residue. Compare only non-latched segments (normal frames ~22 KB), or
route away from Holtburg town center.
**Next probes (in order):**
1. `ACDREAM_DUMP_MOTION=1` + a temporary inbound-position log for the
LOCAL guid: does ACE send position sets for the local player every