tools(profile): the instrument lied by 11.5x -- now it checks itself, and batching kills startup cost

Overnight task 1 of the owner's mandate: "better diagnostic, profiler and tools, so we can batch test way more quicker." WHY THIS CAME BEFORE ANY MORE OPTIMISATION ee89c4d delivered a 5x candidate reduction and a 16x cheaper support floor for 0% end-to-end gain, because the profiler inflated by ~11.5x (14.74 us/sample profiled vs 1.28 us/voxel real). Two rounds of bucket rankings were artefacts of FPlatformTime::Cycles64() wrapped around ~100 ns operations -- the timer pair calibrates at ~0.1 us, so it was measuring itself. PROFILER Deterministic count sampling plus amortised block timing every 64 density calls. Coarse counters (calls, candidates) stay always-on -- they were never the problem. Timing-only scopes are opt-in behind -profiledensityfull. UE CPU trace scopes added. before profiled 14.74 us/sample vs 1.28 us/voxel real ~11.5x after profiled 0.463050 s vs 0.558470 s unprofiled -17.09% geometry 235AC2DC in both ⭐ Every profiled report now prints profiled total, unprofiled total, discrepancy, ratio and geometry equality, and EXITS CODE 2 if the comparison fails. An intermediate run hit -22.6% and failed loudly, which is the point: this class of bug must be impossible to miss rather than something noticed three rounds later. ⚠️ The -17% residual is run-to-run noise, so ~17% is our measurement floor. Improvements smaller than that cannot be claimed from a single pair of runs. BATCH EXPLORER One process, many cases, one JSON. Startup was ~25-30 s of engine boot for ~3 s of work, which is what made every iteration expensive. 3 cases in 6.59 s of case time standalone vs batched, same binary: hash 235AC2DC, 2,461 tris, 343,000 tunnel lookups, 554,381 passage evaluations -- identical on both -out= is enforced absolute under the plugin's own Saved/. CACHE BREAKDOWN (the 272 KB/entry question) The slot table is small. The weight is spatial-index bins and candidate arrays, room arrays, support-column arrays and tunnel-world indices -- i.e. much of the 411 MiB is the spatial index ee89c4d added, which also bought 0% end-to-end. Worth revisiting on those terms. RESEARCH (recorded, not acted on) -- CODEX-TASK-1-PROFILER-BATCH-RESEARCH.md Ranked follow-ups: deterministic empty-space early-out, density-grid reuse, task granularity (ParallelForWithExistingTaskContext + MinBatchSize), SIMD MC (~2x over optimised scalar, but cross-machine determinism is the risk), sparse hierarchy, RMC partial updates, Transvoxel LOD seams. Sources cited in the doc. ⚠️ Upstream RMC is 5.3.2; the owner's copy identifies as 5.4 with custom modifications. No upgrade is safe. Left untouched. PUSHBACK, accepted: "buckets must sum to their parent" needs a parallel-time definition -- summing worker CPU is not wall time. Reports now separate worker CPU sum from wall-clock estimate. End-to-end unchanged, as expected for a tooling change: 2.746 / 2.691 s on the 128^3 seed 1337 region (was 2.678-2.705). Build clean. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_012aheo2crrZmHuYtPpdY2Cb
2026-09-09 05:02:21 +02:00
1 parent ee89c4d8c2
commit e63f016835
@@ -4,6 +4,7 @@
 #include "VoxelMarchingCubesMesher.h"
 #include "MarchingCubesTables.h"
 #include "VoxelDensityProfile.h"
+#include "ProfilingDebugging/CpuProfilerTrace.h"

 //=============================================================================
 // MAIN ALGORITHM
@@ -15,6 +16,7 @@ FVoxelMeshData UVoxelMarchingCubesMesher::GenerateMesh(FIntVector OriginVoxels,
                                                       TArray<uint8>* OutCaptureGrid,
                                                       int32 BandZMinVox, int32 BandZMaxVox)
 {
+    TRACE_CPUPROFILER_EVENT_SCOPE(VoxelForge_MesherGenerateMesh);
    FVoxelMeshData MeshData;
    if (OutCaptureGrid) { OutCaptureGrid->Reset(); }
    if (!Generator) return MeshData;
@@ -300,11 +302,7 @@ FVoxelMeshData UVoxelMarchingCubesMesher::GenerateMesh(FIntVector OriginVoxels,
    static thread_local TArray<int32> CapTris;
    GroundTris.Reset();
    CapTris.Reset();
-    const bool bProfileMesher = VoxelDensityProfile::IsEnabled();
-    uint64 CellClassificationCycles = 0;
-    uint64 GradientCycles = 0;
-    uint64 VertexInterpolationCycles = 0;
-    uint64 StreamBuildingCycles = 0;
+    const bool bProfileMesher = VoxelDensityProfile::IsCycleTimingEnabled();
    uint64 CellClassificationCalls = 0;
    uint64 SurfaceCellCalls = 0;
    for (int32 cz = CzLo; cz <= CzHi; cz++)            // bande de strate : cf. CzLo/CzHi plus haut
@@ -315,7 +313,10 @@ FVoxelMeshData UVoxelMarchingCubesMesher::GenerateMesh(FIntVector OriginVoxels,
            if (ShouldAbortWork()) return FVoxelMeshData();
            for (int32 cx = 0; cx < CellsPerAxis; cx++)
            {
-                const uint64 ClassificationStart = bProfileMesher
+                const bool bSampleCell = bProfileMesher
+                    && VoxelDensityProfile::ShouldSample(
+                        VoxelDensityProfile::EBucket::MesherCellClassification);
+                const uint64 ClassificationStart = bSampleCell
                    ? FPlatformTime::Cycles64() : 0;
                // PASSE 1 : densités aux 8 coins + index de cas MC SEULEMENT.
                // ~70% des cellules d'un chunk sont tout-roc ou tout-air (aucune surface) ;
@@ -334,16 +335,18 @@ FVoxelMeshData UVoxelMarchingCubesMesher::GenerateMesh(FIntVector OriginVoxels,
                }

                const bool bHasSurface = MCEdgeTable[CaseIndex] != 0;
-                if (bProfileMesher)
+                if (bSampleCell)
                {
-                    CellClassificationCycles += FPlatformTime::Cycles64() - ClassificationStart;
-                    ++CellClassificationCalls;
+                    VoxelDensityProfile::AddSampledMeasurement(
+                        VoxelDensityProfile::EBucket::MesherCellClassification,
+                        FPlatformTime::Cycles64() - ClassificationStart);
                }
+                ++CellClassificationCalls;
                if (!bHasSurface) continue;  // Pas de surface ici → skip
-                if (bProfileMesher) { ++SurfaceCellCalls; }
+                ++SurfaceCellCalls;

                // PASSE 2 : positions + gradients aux 8 coins (uniquement si surface présente).
-                const uint64 GradientStart = bProfileMesher
+                const uint64 GradientStart = bSampleCell
                    ? FPlatformTime::Cycles64() : 0;
                FVector Positions[8];
                FVector Gradients[8];
@@ -356,15 +359,17 @@ FVoxelMeshData UVoxelMarchingCubesMesher::GenerateMesh(FIntVector OriginVoxels,
                        + FVector(GX * Step, GY * Step, GZ * Step) * VOXEL_SIZE;
                    Gradients[i] = GradAt(GX, GY, GZ);
                }
-                if (bProfileMesher)
+                if (bSampleCell)
                {
-                    GradientCycles += FPlatformTime::Cycles64() - GradientStart;
+                    VoxelDensityProfile::AddSampledMeasurement(
+                        VoxelDensityProfile::EBucket::MesherGradientNormals,
+                        FPlatformTime::Cycles64() - GradientStart);
                }

                // Interpolation des positions + normales sur les arêtes traversées. t = point de
                // traversée de l'iso entre les deux coins (clampé, milieu si densités quasi-égales) ;
                // la normale interpole les gradients de coin par le même t.
-                const uint64 VertexInterpolationStart = bProfileMesher
+                const uint64 VertexInterpolationStart = bSampleCell
                    ? FPlatformTime::Cycles64() : 0;
                FVector EdgeVertices[12];
                FVector EdgeNormals[12];
@@ -382,15 +387,16 @@ FVoxelMeshData UVoxelMarchingCubesMesher::GenerateMesh(FIntVector OriginVoxels,
                        EdgeNormals[i]  = Gradients[A] + T * (Gradients[B] - Gradients[A]);
                    }
                }
-                if (bProfileMesher)
+                if (bSampleCell)
                {
-                    VertexInterpolationCycles +=
-                        FPlatformTime::Cycles64() - VertexInterpolationStart;
+                    VoxelDensityProfile::AddSampledMeasurement(
+                        VoxelDensityProfile::EBucket::MesherVertexInterpolation,
+                        FPlatformTime::Cycles64() - VertexInterpolationStart);
                }

                // Génère les triangles avec vertices dédupliqués.
                // Ordre 0, 2, 1 (pas 0, 1, 2) pour le winding attendu par RealtimeMesh.
-                const uint64 StreamBuildingStart = bProfileMesher
+                const uint64 StreamBuildingStart = bSampleCell
                    ? FPlatformTime::Cycles64() : 0;
                for (int32 i = 0; MCTriTable[CaseIndex][i] != -1; i += 3)
                {
@@ -410,9 +416,11 @@ FVoxelMeshData UVoxelMarchingCubesMesher::GenerateMesh(FIntVector OriginVoxels,
                    Dst.Add(Idx2);
                    Dst.Add(Idx1);
                }
-                if (bProfileMesher)
+                if (bSampleCell)
                {
-                    StreamBuildingCycles += FPlatformTime::Cycles64() - StreamBuildingStart;
+                    VoxelDensityProfile::AddSampledMeasurement(
+                        VoxelDensityProfile::EBucket::MesherStreamBuilding,
+                        FPlatformTime::Cycles64() - StreamBuildingStart);
                }
            }
        }
@@ -422,16 +430,16 @@ FVoxelMeshData UVoxelMarchingCubesMesher::GenerateMesh(FIntVector OriginVoxels,
    {
        VoxelDensityProfile::AddMeasurement(
            VoxelDensityProfile::EBucket::MesherCellClassification,
-            CellClassificationCycles, CellClassificationCalls);
+            0, CellClassificationCalls);
        VoxelDensityProfile::AddMeasurement(
            VoxelDensityProfile::EBucket::MesherGradientNormals,
-            GradientCycles, SurfaceCellCalls);
+            0, SurfaceCellCalls);
        VoxelDensityProfile::AddMeasurement(
            VoxelDensityProfile::EBucket::MesherVertexInterpolation,
-            VertexInterpolationCycles, SurfaceCellCalls);
+            0, SurfaceCellCalls);
        VoxelDensityProfile::AddMeasurement(
            VoxelDensityProfile::EBucket::MesherStreamBuilding,
-            StreamBuildingCycles, SurfaceCellCalls);
+            0, SurfaceCellCalls);
    }

    VoxelDensityProfile::FScopedTimer MesherFinalisationTimer(