#119 decisive probe: ACDREAM_DUMP_ENTITY one-shot entity dump (H-A/H-B/H-C discriminator)

The broken-state log (user-session-capture2.log) shows meshMissing=0 /
entSeen==entDrawn WHILE broken stairs are on screen - the staircase is
DRAWN WRONG, not missing. This probe discriminates the three live
hypotheses in ONE launch (handoff 2026-06-11 s4):

- HYDRATE dump (GameWindow.BuildInteriorEntitiesForStreaming): per-part
  placement-frame translations + dropped-part accounting at the MOMENT
  MeshRefs are constructed. H-A (SetupMesh.Flatten identity fallback /
  silent gfx-null part drops under degraded dat reads) shows here as
  zero translations or built<43.
- DRAW dump (WbDrawDispatcher, first tuple per entity): live MeshRefs
  translation summary + per-part loaded flags + Tier-1 classification
  cache state (batch count + RestPose translation summary), re-emitted
  compactly on signature change. H-B (partial/stale cached batch set)
  shows as correct translations + odd batch count.
- WALK-REJECT lines (rate-limited): attributes 'entity never reaches
  the draw loop' to the specific gate (visibleCellIds/frustum).
- Correct everything -> H-C (draw-side compose), instrument next.

Targets: ACDREAM_DUMP_ENTITY=0x020003F2,0x020005D8 (the 43-part spiral
staircase Setup + the wall barrels; H-A predicts the user's 'barrel' IS
the collapsed staircase). Probe is inert when the env var is unset.
Parser in RenderingDiagnostics (diagnostic-owner pattern) + 5 unit tests.

Suites: App 242+1skip / Core 1427+2skip / UI 420 / Net 294.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Erik 2026-06-11 21:01:08 +02:00
parent d82f070b88
commit 3cf6bcc219
4 changed files with 246 additions and 2 deletions

View file

@ -251,6 +251,21 @@ public sealed unsafe class WbDrawDispatcher : IDisposable
private readonly HashSet<ulong> _missRequested = new();
private readonly HashSet<ulong> _missLogged = new();
// #119 decisive probe (2026-06-11): ACDREAM_DUMP_ENTITY one-shot entity
// dump. Keyed by entity Id; the stored signature re-emits the header line
// whenever (MeshRefs count, cache batch count, zero-translation count,
// culled) changes — e.g. the Tier-1 populate landing one frame after the
// first slow-path draw. The full per-part listing prints only on first
// sight. Inert (one Count==0 check per new entity) when the env var is
// unset. Render-thread only.
private readonly Dictionary<uint, (int MeshRefCount, int CacheBatches, int ZeroT, bool Culled)> _entityDumpSig = new();
// Rate limiter for [dump-entity] WALK-REJECT lines: a rejected entity
// re-tests every frame; emit the first rejection per entity then every
// 300th (~5 s at 60 fps). Static because WalkEntitiesInto is static;
// render-thread only like the walk itself.
private static readonly Dictionary<uint, int> _walkRejectCounts = new();
// CPU + GPU timing for [WB-DIAG] under ACDREAM_WB_DIAG=1.
private readonly System.Diagnostics.Stopwatch _cpuStopwatch = new();
private readonly long[] _cpuSamples = new long[256]; // microseconds
@ -662,6 +677,7 @@ public sealed unsafe class WbDrawDispatcher : IDisposable
if (!cellInVis)
{
if (shellScoped) result.BuildingShellAnchorReject++;
MaybeEmitWalkRejectDump(entity, "visibleCellIds-miss");
if (isCellEntity && RenderingDiagnostics.ProbeIndoorCullEnabled
&& indoorProbeState!.ShouldEmit(cellProbeId))
{
@ -687,6 +703,7 @@ public sealed unsafe class WbDrawDispatcher : IDisposable
if (!aabbVisible)
{
MaybeEmitWalkRejectDump(entity, "frustum");
if (isCellEntity && RenderingDiagnostics.ProbeIndoorCullEnabled
&& indoorProbeState!.ShouldEmit(cellProbeId))
{
@ -719,6 +736,94 @@ public sealed unsafe class WbDrawDispatcher : IDisposable
}
}
/// <summary>
/// #119 decisive probe: rate-limited <c>[dump-entity] WALK-REJECT</c> line
/// for an <c>ACDREAM_DUMP_ENTITY</c>-targeted entity that the walk filtered
/// out (visibleCellIds gate / per-entity frustum). Absence of any DRAW dump
/// plus presence of these lines attributes "entity exists but never reaches
/// the draw loop" to the specific gate. Inert when the target set is empty.
/// </summary>
private static void MaybeEmitWalkRejectDump(WorldEntity entity, string reason)
{
var targets = RenderingDiagnostics.DumpEntitySourceIds;
if (targets.Count == 0 || !targets.Contains(entity.SourceGfxObjOrSetupId)) return;
_walkRejectCounts.TryGetValue(entity.Id, out int n);
_walkRejectCounts[entity.Id] = n + 1;
if (n % 300 != 0) return;
Console.WriteLine(
$"[dump-entity] WALK-REJECT id=0x{entity.Id:X8} src=0x{entity.SourceGfxObjOrSetupId:X8} " +
$"reason={reason} parentCell=0x{(entity.ParentCellId ?? 0u):X8} " +
$"pos=({entity.Position.X:F2},{entity.Position.Y:F2},{entity.Position.Z:F2}) n={n + 1}");
}
/// <summary>
/// #119 decisive probe: per-entity state dump at draw time for
/// <c>ACDREAM_DUMP_ENTITY</c>-targeted entities. First sight prints a
/// header + every MeshRef's GfxObj id, part-transform translation, and
/// loaded flag; afterwards a compact header re-emits only when the
/// (meshRefs, cacheBatches, zeroTranslations, culled) signature changes.
/// Discriminates H-A (hydration-time MeshRef corruption: translations
/// collapsed to ~zero / missing parts) from H-B (Tier-1 cache holding a
/// partial or stale batch set) from H-C (both healthy ⇒ draw-side compose).
/// </summary>
private void MaybeEmitEntityDump(WorldEntity entity, uint landblockId, bool culled)
{
var targets = RenderingDiagnostics.DumpEntitySourceIds;
if (targets.Count == 0 || !targets.Contains(entity.SourceGfxObjOrSetupId)) return;
var refs = entity.MeshRefs;
int zeroT = 0;
float tzMin = float.MaxValue, tzMax = float.MinValue;
for (int i = 0; i < refs.Count; i++)
{
var t = refs[i].PartTransform.Translation;
if (t.LengthSquared() < 1e-9f) zeroT++;
if (t.Z < tzMin) tzMin = t.Z;
if (t.Z > tzMax) tzMax = t.Z;
}
int cacheBatches = -1;
int restZero = 0;
float rzMin = float.MaxValue, rzMax = float.MinValue;
if (_cache.TryGet(entity.Id, landblockId, out var cacheEntry))
{
cacheBatches = cacheEntry!.Batches.Length;
foreach (var b in cacheEntry.Batches)
{
var t = b.RestPose.Translation;
if (t.LengthSquared() < 1e-9f) restZero++;
if (t.Z < rzMin) rzMin = t.Z;
if (t.Z > rzMax) rzMax = t.Z;
}
}
var sig = (refs.Count, cacheBatches, zeroT, culled);
bool first = !_entityDumpSig.TryGetValue(entity.Id, out var prev);
if (!first && prev == sig) return;
_entityDumpSig[entity.Id] = sig;
string cacheStr = cacheBatches < 0
? (_tier1CacheDisabled ? "disabled" : "miss")
: $"hit:{cacheBatches} restZero={restZero} restZ=[{rzMin:F2}..{rzMax:F2}]";
Console.WriteLine(
$"[dump-entity] DRAW{(first ? "" : "-CHANGED")} id=0x{entity.Id:X8} src=0x{entity.SourceGfxObjOrSetupId:X8} " +
$"lb=0x{landblockId:X8} cell=0x{(entity.ParentCellId ?? 0u):X8} " +
$"pos=({entity.Position.X:F2},{entity.Position.Y:F2},{entity.Position.Z:F2}) scale={entity.Scale:F2} " +
$"meshRefs={refs.Count} tZero={zeroT} tZ=[{tzMin:F2}..{tzMax:F2}] cache={cacheStr} culled={culled}");
if (first)
{
for (int i = 0; i < refs.Count; i++)
{
var mr = refs[i];
var t = mr.PartTransform.Translation;
bool loaded = _meshAdapter.TryGetRenderData(mr.GfxObjId) is not null;
Console.WriteLine(
$"[dump-entity] part[{i:D2}] gfx=0x{mr.GfxObjId:X8} t=({t.X:F3},{t.Y:F3},{t.Z:F3}) loaded={loaded}");
}
}
}
public void Draw(
ICamera camera,
IEnumerable<(uint LandblockId, Vector3 AabbMin, Vector3 AabbMax,
@ -920,6 +1025,11 @@ public sealed unsafe class WbDrawDispatcher : IDisposable
_cellIdToSlot, _outdoorSlot, _outdoorVisible);
if (_currentEntityCulled)
probeCulledEntities++;
// #119 decisive probe: one-shot dump (+ change re-emission) for
// ACDREAM_DUMP_ENTITY-targeted entities. Before the culled-continue
// so a routed-out entity still reports its state.
MaybeEmitEntityDump(entity, landblockId, _currentEntityCulled);
}
prevTupleEntityId = entity.Id;