VoxelForge/PERF-ATTRIBUTION.md

PERF-ATTRIBUTION

Measured 2026-09-12 at cf0319d (experimental). This was measurement-only: the source changes add diagnostic counters and clocks; they do not change density or meshing decisions. The primary case is the 128^3 TunnelNetwork, seed 1337, slot 1, operator-stack setting 1, origin (-64,-64,-224) voxels, step 1, 64 canonical 32^3 tiles, and 15 workers.

clean means diagnostics off and -blockearlyout=0, with fused evaluation and shared density-grid reuse enabled. The three clean primary runs used an exact-HEAD DLL staged before instrumentation: 603.599, 590.746, and 569.627 ms mesh time, mean 587.991 ms. The requested 0.556 s is therefore within the observed run spread but was not reproduced exactly on this host. attr means the final instrumented DLL, -perfattribution, sample interval 128. Its wall-clock self-check compares the same export against an unprofiled run in the same process.

The prescribed build was run successfully with:

dotnet "E:\Program Files\Epic Games\UE_5.7\Engine\Binaries\DotNET\UnrealBuildTool\UnrealBuildTool.dll" UnrealEditor Win64 Development "-Project=E:\Projet Unreal\VoxelM\Plugins\VoxelForge\Saved\BuildHost\HostProject\HostProject.uproject" -WaitMutex -FromMsBuild -architecture=x64 -NoUBA "-Log=E:\Projet Unreal\VoxelM\Plugins\VoxelForge\Saved\PerfAttributionBuild.log"

The measured process loaded the staged runtime DLL at E:\Projet Unreal\VoxelM\Plugins\VoxelForge\Saved\BuildHost\HostProject\Plugins\VoxelForge\Binaries\Win64\UnrealEditor-VoxelForge.dll, SHA-256 C0CB812BB25EFE8C836DC1C1718C408DA5FE9D9F258B4AE12A6CA846510CA0B2, length 7,673,856 bytes. The staged editor DLL was E64C9E80869EFA53FA1556947718DB8E64975ABF6B546657BCFF5D775A2B679A, length 502,784 bytes. The game harness recorded the same runtime path and hash. The primary attribution and final classifier exports returned status=ok, geometry CRC 07C14005, and the required OBJ SHA-256 b3e5f4c398dd0547c6c55f415872058246d4a292c2f0d636ee1cd0829de9b377.

The table is the attribution. Only rows marked additive are summed. Profiler component rows are sampled nested diagnostics; their CPU and worker-wall figures are evidence about composition, not additional time to add to the wall ledger.

Bucket / question	Measurement and mode	Elapsed time, volume, or count	Whole-clock accounting / interpretation
Historical comparison	34f06df value supplied in the request	130.000 ms	Historical pre-op-stack reference; the exact old binary was not rebuilt because that commit predates the current editor commandlet and host harness.
Current clean primary	3 exports, exact cf0319d DLL, diagnostics off, fused=1, reuse=1, classifier early-out=0	587.991 ms mean; 569.627–603.599 ms	Clean headline mesh clock. Mean is 4.523x the supplied 130 ms reference.
Primary attribution self-check	Final DLL, attr; profiled 606.128 ms versus same-argument unprofiled 602.341 ms	1.0063x; +0.629%	Passed. Geometry equal. The profiler did not reproduce the 11.5x inflation seen in the earlier diagnostic mode.
Full commandlet export	Final DLL, attr; mesh plus output and bookkeeping	1,004.557 ms	Full export wall, not just mesh generation. The OBJ writer is a material part of this clock.
Full export: mesh generation	Additive export ledger	606.128 ms; 60.338% of export	Includes the complete additive mesh ledger below.
Full export: OBJ/output interval	Additive; includes nested MeasureExploreMesh	394.273 ms; 39.249%	measure_seconds is 82.964 ms inside this interval and is not added again.
Full export: geometry hash	Additive	2.946 ms; 0.293%	CRC/hash bookkeeping.
Full export: manifest	Additive	0.984 ms; 0.098%	Manifest write.
Full export: remainder	Additive export remainder	0.225 ms; 0.022%	Export ledger remainder. Mesh + OBJ interval + hash + manifest + remainder = 1,004.557 ms.
Mesh ledger: preparation	Additive	0.000101 ms; 0.0000% of mesh	No meaningful cost.
Mesh ledger: shared density-grid fill	Additive; 2,248,091 unique shared samples	590.923 ms; 97.4913% of mesh	This is the dominant remaining cost. It is the caller-side density-grid stage and includes the canonical fused GetDensityAt work.
Mesh ledger: pre-tile setup	Additive	0.001602 ms; 0.0003%	No meaningful cost.
Mesh ledger: tile parallel wall	Additive; 64 jobs, 15 workers	10.972 ms; 1.8102%	Per-tile cell scan, interpolation, normals, stream assembly, and task scheduling after the shared grid exists.
Mesh ledger: tile merge	Additive	4.232 ms; 0.6982%	Cross-tile output merge.
Mesh ledger: accounting remainder	Additive	0.000097 ms; 0.0000%	Stage sum 606.128205 ms versus mesh clock 606.128301 ms; sum_matches_mesh=true. Nothing is hidden in this remainder.
Mesh ledger total	Final DLL, attr	606.128301 ms	Complete mesh wall clock.
GetDensityAt parent	Final primary, attr; 2,248,091 calls, 17,558 sampled parent intervals, 15 workers	580.184 ms worker-wall estimate	Nested inside the 590.923 ms density-grid stage. The remaining 10.738 ms is grid-loop/task/read overhead outside the parent scope; it is accounted for by the additive density-grid row.
Fused evaluator itself	Final primary, attr; 17,571 sampled component scopes; 2,248,091 fused tunnel samples	107.183 ms sampled CPU; 12.301 ms sampled worker wall	Diagnostic sample only, not additive. Detail ran for 1,079,777 samples and was skipped for 1,168,314, about 52.0% of fused lattice samples.
Fused density core	Final primary, attr; sampled nested scope	108.371 ms sampled CPU; 12.377 ms sampled worker wall	Diagnostic sample only. It is not a 108 ms total bucket and must not be added to the mesh ledger.
Room/tunnel graph traversal	Final primary counters	Rooms: 11,099,891 candidates / 1,730,920 evaluated; tunnels: 28,951,420 candidates / 3,462,565 evaluated; tunnel-core: 28,951,420 candidates / 1,881,812 evaluated	Room and tunnel candidate traversal is repeated inside the common density work. This is evidence of work volume, not a separately additive clock.
Room graph build and SDF	Final primary, attr	RoomGraphBuild: 77 calls, 192.146 ms sampled CPU / 19.323 ms worker wall; RoomGraphSdf: 12.101 ms / 0.989 ms sampled CPU/wall	The build is cold/cache construction work; SDF figures are nested samples. The room graph is not a large independent wall bucket on the primary fused route.
Tunnel-core world evaluation	Final primary, attr	8.857 ms sampled CPU; 0.872 ms sampled worker wall	Nested diagnostic sample. The core traversal is present, but the measured evidence does not support calling it the whole 4.3x.
Post-stack structural/passage tail	Final primary, attr; GetDensityAt tail	StructuralTail: 20.853 ms CPU / 1.896 ms wall; DensityStructuralPosts: 21.909 ms / 1.990 ms; PassageStructuralPosts: 10.476 ms / 0.997 ms sampled CPU/wall	This is real current-only post-stack work, but it is a small sampled component relative to the 590.923 ms density-grid wall. All rows are nested and non-additive. Passage modifier was 4.579 ms CPU / 0.404 ms wall; landing-floor and room-floor samples were 1.691 ms / 0.177 ms and 0.665 ms / 0.060 ms.
Floor/profile work	Final primary counters, fused route; classifier figures from the separate classifier control	Primary support-column builds/queries/checks: 0 / 0 / 0; authored-floor samples: 0; floor-profile builds 2,636; segments 12,624; backstops 6,509 tunnel and 49 room. Classifier control: 211,289 support-column builds, 2,171,763 candidates, 1,370,314 floor queries, 2,296,243 checks, 9,710 authored-floor samples, 97,950 profiles and 442,278 profile segments.	The fused primary route does not execute the classifier’s support-column path. The classifier does, and that work is part of its separate 2.057 s route, not the clean 0.588 s headline.
Software tunnel cache	Final primary, attr	2,248,043 hits, 48 misses, 77 cache builds	Cache lookup is not the removed verdict cache. The current tunnel cache is overwhelmingly hit; no hardware cache-miss counter was available.
Classifier absent from the clean headline	Clean exact-HEAD control, diagnostics off, classifier early-out=0	0 classifier calls	The stated 0.556 s case does not pay interval proofs. It is incorrect to charge classifier time to that baseline.
Classifier control when enabled	3 clean exact-HEAD controls, diagnostics off, classifier early-out=1	2,056.596 ms mean	+1,468.605 ms versus the clean primary mean; 3.498x the primary. This is a separate, expensive route, not the source of the clean 0.556 s.
Classifier total self-check	Final DLL, attr, classifier early-out=1	1,980.835 ms profiled versus 2,013.547 ms unprofiled; 0.9838x	Passed; geometry equal. Profile overhead was -1.62% in this run.
Interval proofs	Final classifier attribution; 32 sampled calls out of 4,096	494,976 refine/box calls; 479,872 whole-mixed, 15,104 whole-solid, 0 whole-air; 63,488 splits; max depth 4	Proof detail is present and conservative, but its route is costly. The classifier’s scaled diagnostic work was 14,113.190 ms interval-box, 62.221 ms exact-core, and 399.770 ms exact-final microseconds; these are diagnostic work estimates, not additive wall time.
Classifier repeated room traversal	Final classifier attribution	2,041,600 room-tail queries, 933,120 evaluated; 6,030,720 exact-core cache hits; 612,864 exact-core samples; 768 exact-final samples	The classifier does repeat room-graph work. Scaled diagnostic work was 11,423.590 ms room propagation, 4,665.818 ms exact primitive, 5,815.002 ms cache-window, and 1,227.366 ms room tail microseconds.
Shared grid traffic	Final primary, attr	2,744,000 tile-grid samples; 2,248,091 unique shared samples; 495,909 duplicate evaluations before reuse, 0 after	The shared lattice removes duplicate evaluations, but filling the remaining 2.248 M samples is still 590.923 ms.
Mesher cell classification	Final primary, attr; nested sample	2,097,152 cell calls; 1.344 ms sampled worker wall	The cell loop is not the dominant wall bucket.
Mesher vertex interpolation	Final primary, attr; nested sample	76,808 calls; 0.012 ms sampled worker wall	Negligible in the observed sample.
Mesher gradient normals	Final primary, attr; nested sample	76,808 calls; 1.056 ms sampled worker wall	Small nested cost; gradient normals come from the density grid.
Mesher stream building	Final primary, attr; nested sample	76,808 calls; 3.140 ms sampled worker wall	Small relative to density-grid fill. Runtime stream handoff is not executed by the export commandlet.
Mesher output and memory	Final primary, attr	82,273 vertices, 153,346 triangles; logical output arrays 7,434,716 bytes; allocated output 8,449,820 bytes; OBJ 17,587,937 bytes; estimated working set 14,851,564 bytes	Byte counters are logical allocator/output traffic, not physical DRAM traffic.
Grid read/write bytes	Final primary, attr	Density-grid bytes 10,976,000; shared-grid read bytes 10,976,000	The instrumentation sees logical grid traffic. It does not see hardware cache misses, NUMA traffic, or memory-controller events.
Operator-block scratch/copy	Final primary, attr	0 scratch bytes, 0 copy bytes, 0 builds, 0 operators	The old interpreted block machinery is not on the canonical primary route.
Operator-block control	Clean diagnostics-off controls with reuse=0 and fused=0	2,332.186 ms; 1,566 block builds; 2,486,750 block samples; 31,320 operator visits; 99,470,000 scratch bytes; 101,956,750 copy bytes	This is a deliberately separate block-path control, not the clean fused baseline. It demonstrates the traffic that is absent from the primary route.
Scalar and fused no-reuse controls	Clean diagnostics-off controls with reuse=0	Scalar 2,733.080 ms; fused 2,218.132 ms	These controls show the cost of removing shared-grid reuse, but they are not attribution buckets for the primary run.
What 34f06df did not do	Read-only source comparison at the historical commit	No active TunnelNetwork operator-stack evaluation, no fused evaluator, no current post-stack tunnel-floor/structural tail, no current editor export commandlet	The old source already had a shared density grid, ClassifyTile, marching-cubes cell classification, interpolation, grid-gradient normals, and stream construction. Those are not new current-only work. The old source also had room/tunnel morphology and passage carving, so “rooms/tunnels exist” alone is not a delta.
Primary operation-level attribution gap	Final primary profiler’s own ledger	Sampled phase sum 14.443 ms versus sampled GetDensityAt parent 580.184 ms; sampling gap 565.741 ms	This is the honest limit: component scopes were sampled to keep profiled/unprofiled totals within 0.63%, so their expanded operation-level wall shares are not identifiable from this run. The full mesh wall is nevertheless closed by the additive stage ledger, with a 0.000097 ms remainder.
Headless game clean check	PerfAttribGameCleanFinal_20260912; diagnostics off, tile profiling off; 343 LOD0-ready samples	request-to-ready p95 0.375470 s; queue wait p95 0.082292 s; generation p95 0.309538 s; collision cook p95 0.052945 s	Secondary check agrees with the earlier conclusion that queue wait is not the main generation constraint.
Headless game attribution check	PerfAttribGameAttrFinal_20260912; diagnostics on, tile profiling on; 834 profile lines, 822 applied	request-to-ready p95 0.395715 s; queue wait p95 0.083363 s; generation p95 0.315281 s; collision cook p95 0.061387 s	Attribution overhead was modest in the end-to-end game summary. Tile-profile p95 was 1.295847 s, of which classifier was 0.106626 s, mesh 1.284040 s, stream building 0.000361 s, room work 0.008842 s, and stack work 0.012019 s; these game tiles are not the same workload as the single 128^3 export.

The surprise is that the clean primary is almost entirely the shared density-grid fill: the ordinary mesher stages after it total only about 15.204 ms. The fused evaluator is genuinely on the canonical path, and the room/tunnel candidate counters show substantial repeated traversal, but the sampled component timers cannot honestly turn that 590.923 ms into exact per-operation percentages without reintroducing the profiler inflation this round was designed to avoid. The classifier is an even larger cost when enabled, yet it is absent from the clean baseline. The old path already performed the grid and marching-cubes phases, so those phases should not be described as newly introduced work; the current-only items are the active fused route and the later structural/floor machinery.

What could not be attributed: physical allocation-event counts, physical memory/cache misses, and an exact numeric per-operation delta against the old 34f06df binary. The old commit has no compatible current export commandlet, and rebuilding it would not be the same measurement harness. The complete current clocks, deterministic geometry, clean/profiled comparison, current counters, and all logical memory-byte counters are accounted for above. Existing logs and outputs under Saved\ were retained.