diff --git a/src/AcDream.App/Composition/SessionPlayerComposition.cs b/src/AcDream.App/Composition/SessionPlayerComposition.cs index 1baac0b7..2af1a65b 100644 --- a/src/AcDream.App/Composition/SessionPlayerComposition.cs +++ b/src/AcDream.App/Composition/SessionPlayerComposition.cs @@ -425,7 +425,8 @@ internal sealed class SessionPlayerCompositionPhase spawnClaimClassifier.IsUnhydratable, worldQuiescence, streaming, - revealRenderResources); + revealRenderResources, + () => live.WorldState.LoadedLandblockCount); Fault(SessionPlayerCompositionPoint.WorldRevealCreated); return CompleteSessionPlayer( diff --git a/src/AcDream.App/Streaming/GpuWorldState.cs b/src/AcDream.App/Streaming/GpuWorldState.cs index 5504862c..ce8cb764 100644 --- a/src/AcDream.App/Streaming/GpuWorldState.cs +++ b/src/AcDream.App/Streaming/GpuWorldState.cs @@ -198,6 +198,10 @@ public sealed class GpuWorldState : ILiveEntitySpatialQuery /// that need to enumerate entities before the landblock is dropped /// (e.g. unregistering dynamic lights on a RemoveLandblock). /// + /// Resident landblock count — reveal-timing probe progress + /// lines only (). + public int LoadedLandblockCount => _loaded.Count; + public bool TryGetLandblock(uint landblockId, out LoadedLandblock? lb) { if (_loaded.TryGetValue(landblockId, out var found)) diff --git a/src/AcDream.App/Streaming/RevealTimingProbe.cs b/src/AcDream.App/Streaming/RevealTimingProbe.cs new file mode 100644 index 00000000..2b2d9f7b --- /dev/null +++ b/src/AcDream.App/Streaming/RevealTimingProbe.cs @@ -0,0 +1,155 @@ +using System.Diagnostics; +using AcDream.Runtime; + +namespace AcDream.App.Streaming; + +/// +/// ACDREAM_PROBE_REVEAL_TIMING=1 (see +/// ): wall-clock +/// attribution of one login/portal hold. Emits [reveal-timing] lines: +/// +/// +/// event=begin — the hold starts, with the required window and +/// its landblock count. +/// event=render-ready / composites-ready / collision-ready / +/// gate-ready / materialized — first-true edges with elapsed ms. The +/// readiness barrier OBSERVES the dimensions serially (composites are only +/// evaluated once render is ready, collision once both are), so each edge's +/// delta over the previous one is that dimension's observed TAIL, not its +/// total concurrent cost — the progress lines carry the concurrency +/// shape. +/// 1 Hz progress — elapsed, the three flags, and the resident +/// landblock count, so a budget-paced linear drip is visually obvious in the +/// log. +/// SUMMARY once at the viewport reveal — the per-edge +/// timeline on one line. +/// +/// +/// Diagnostic-only: never constructed unless the probe env is set, changes +/// no behavior, and costs one branch per Evaluate poll otherwise. +/// +internal sealed class RevealTimingProbe +{ + private readonly Func? _loadedLandblockCount; + private readonly Stopwatch _clock = new(); + private long _generation; + private string _kind = ""; + private int _windowLandblocks; + private bool _render; + private bool _composites; + private bool _collision; + private bool _gateReady; + private bool _materialized; + private bool _summarized; + private long _renderMs = -1; + private long _compositesMs = -1; + private long _collisionMs = -1; + private long _gateReadyMs = -1; + private long _materializedMs = -1; + private long _lastProgressMs; + + public RevealTimingProbe(Func? loadedLandblockCount) => + _loadedLandblockCount = loadedLandblockCount; + + public void Begin( + string kind, + long generation, + uint destinationCell, + in StreamingRevealWindow window) + { + _generation = generation; + _kind = kind; + int side = window.FarRadius * 2 + 1; + _windowLandblocks = side * side; + _render = false; + _composites = false; + _collision = false; + _gateReady = false; + _materialized = false; + _summarized = false; + _renderMs = -1; + _compositesMs = -1; + _collisionMs = -1; + _gateReadyMs = -1; + _materializedMs = -1; + _lastProgressMs = 0; + _clock.Restart(); + Console.WriteLine( + $"[reveal-timing] event=begin kind={kind} gen={generation} " + + $"cell=0x{destinationCell:X8} window={window.NearRadius}/" + + $"{window.FarRadius} landblocks={_windowLandblocks} " + + $"loaded={_loadedLandblockCount?.Invoke() ?? -1}"); + } + + public void Observe( + in WorldRevealReadinessSnapshot readiness, + in RuntimePortalSnapshot portal) + { + if (_generation == 0 || portal.Generation != _generation) + return; + + long elapsed = _clock.ElapsedMilliseconds; + if (!_render && readiness.IsRenderNeighborhoodReady) + { + _render = true; + _renderMs = elapsed; + Edge("render-ready", elapsed); + } + if (!_composites && readiness.AreCompositeTexturesReady) + { + _composites = true; + _compositesMs = elapsed; + Edge("composites-ready", elapsed); + } + if (!_collision && readiness.IsCollisionReady) + { + _collision = true; + _collisionMs = elapsed; + Edge("collision-ready", elapsed); + } + if (!_gateReady && readiness.IsReady) + { + _gateReady = true; + _gateReadyMs = elapsed; + Edge("gate-ready", elapsed); + } + if (!_materialized && portal.Materialized) + { + _materialized = true; + _materializedMs = elapsed; + Edge("materialized", elapsed); + } + + if (!_summarized && portal.WorldViewportObserved) + { + _summarized = true; + Console.WriteLine( + $"[reveal-timing] SUMMARY kind={_kind} gen={_generation} " + + $"totalMs={elapsed} renderMs={_renderMs} " + + $"compositesMs={_compositesMs} collisionMs={_collisionMs} " + + $"gateReadyMs={_gateReadyMs} " + + $"materializedMs={_materializedMs} " + + $"landblocks={_windowLandblocks}"); + return; + } + + if (!_summarized && elapsed - _lastProgressMs >= 1000) + { + _lastProgressMs = elapsed; + Console.WriteLine( + $"[reveal-timing] elapsedMs={elapsed} " + + $"render={(_render ? 1 : 0)} " + + $"composites={(_composites ? 1 : 0)} " + + $"collision={(_collision ? 1 : 0)} " + + $"loaded={_loadedLandblockCount?.Invoke() ?? -1}" + + $"/{_windowLandblocks}"); + } + } + + private void Edge(string name, long elapsed) => + Console.WriteLine( + $"[reveal-timing] event={name} kind={_kind} gen={_generation} " + + $"elapsedMs={elapsed} " + + $"loaded={_loadedLandblockCount?.Invoke() ?? -1}" + + $"/{_windowLandblocks}"); +} diff --git a/src/AcDream.App/Streaming/StreamingDiagnostics.cs b/src/AcDream.App/Streaming/StreamingDiagnostics.cs index d40471f4..5102b484 100644 --- a/src/AcDream.App/Streaming/StreamingDiagnostics.cs +++ b/src/AcDream.App/Streaming/StreamingDiagnostics.cs @@ -51,6 +51,19 @@ internal static class StreamingDiagnostics far); } + /// + /// Login-load measurement probe (2026-08-17): when set, the reveal + /// coordinator emits a [reveal-timing] wall-clock timeline for + /// every login/portal hold — per-dimension first-ready edges + /// (render neighborhood, composite textures, collision), 1 Hz progress + /// with the resident-landblock count, and one summary line at the + /// viewport reveal — so optimization targets the measured dominant + /// phase instead of a guess. Diagnostic-only: not a user setting, not + /// persisted, no behavior change. + /// + public static bool ProbeRevealTiming { get; } = + Environment.GetEnvironmentVariable("ACDREAM_PROBE_REVEAL_TIMING") == "1"; + /// /// The floor is 1, not 0. An outdoor destination's acknowledgement must /// carry RequiredRenderRadius >= 1 or diff --git a/src/AcDream.App/Streaming/WorldRevealCoordinator.cs b/src/AcDream.App/Streaming/WorldRevealCoordinator.cs index d8ee6b44..8e74ab1e 100644 --- a/src/AcDream.App/Streaming/WorldRevealCoordinator.cs +++ b/src/AcDream.App/Streaming/WorldRevealCoordinator.cs @@ -68,6 +68,7 @@ internal sealed class WorldRevealCoordinator private readonly IWorldRevealStreamingScheduler? _streaming; private readonly IWorldRevealRenderResourceScheduler? _renderResources; private readonly List _hostProjections = []; + private readonly RevealTimingProbe? _timing; private bool _hostRetryActive; private bool _hostRetryRequested; @@ -83,7 +84,8 @@ internal sealed class WorldRevealCoordinator Func isSpawnClaimUnhydratable, WorldGenerationQuiescence? quiescence = null, IWorldRevealStreamingScheduler? streaming = null, - IWorldRevealRenderResourceScheduler? renderResources = null) + IWorldRevealRenderResourceScheduler? renderResources = null, + Func? loadedLandblockCount = null) { _transit = transit ?? throw new ArgumentNullException(nameof(transit)); _readiness = new WorldRevealReadinessBarrier( @@ -98,6 +100,8 @@ internal sealed class WorldRevealCoordinator _quiescence = quiescence; _streaming = streaming; _renderResources = renderResources; + if (StreamingDiagnostics.ProbeRevealTiming) + _timing = new RevealTimingProbe(loadedLandblockCount); } public RuntimePortalSnapshot Snapshot => _transit.Snapshot; @@ -117,6 +121,11 @@ internal sealed class WorldRevealCoordinator _quiescence?.CaptureBegin() ?? default; _readiness.Begin(); long generation = _transit.BeginLoginReveal(destinationCell); + _timing?.Begin( + "login", + generation, + destinationCell, + _readiness.RequiredWindow(destinationCell)); BeginHostLifetime( generation, destinationCell, @@ -151,6 +160,11 @@ internal sealed class WorldRevealCoordinator } _readiness.Begin(); + _timing?.Begin( + "portal", + generation, + destinationCell, + _readiness.RequiredWindow(destinationCell)); BeginHostLifetime( generation, destinationCell, @@ -195,6 +209,7 @@ internal sealed class WorldRevealCoordinator WorldRevealReadinessSnapshot snapshot = _readiness.Evaluate(destinationCell); ReconcileDestinationReservationRadius(snapshot); RuntimePortalSnapshot portal = _transit.Snapshot; + _timing?.Observe(snapshot, portal); if (portal.Generation != 0) { _transit.AcknowledgeDestinationReadiness(