chore(repo): archive historical docs under Docs/archive, drop tracked pycache
Move closed audits, task briefs, design rounds, perf reports, the OPSTACK plan/progress logs and WORK-NEXT.md into Docs/archive/ (git mv, history kept). Whitelist Docs/ in the strict .gitignore, ignore Tools/**/__pycache__/, and remove the tracked .pyc. Repoint references in the kept docs and in non-test source comments to the new paths.
This commit is contained in:
34 files changed
+20
-15
No files matched your search
@@ -0,0 +1,93 @@
|
||||
# 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:
|
||||
|
||||
```text
|
||||
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.
|
||||
Reference in new issue
Block a user