Add GPU diagnostics and close periodic profiles per frame (#225)
Add periodic encoder profiles with attachment traffic and formats, alternating A/B measurement phases, bounded Metal trace capture, and gpuprof.py log summaries. Preserve main's offline pipeline-archive integration while adding the capture build setting. Close periodic samples at frame boundaries through the last committed shared-event fence, so every:1 reports without mixing frames or reusing an unresolved heap. Add 28 CPU checks of production profiling code and include them in CI; document the mechanism and update the symptom index. Validated with all 31 CI-style Python test files, the profiling regression, a Mac host build, and all 133 iOS source compiles. Profiling completion and heap ownership were checked with synthetic counter/event objects; no new real-GPU or gameplay validation. Co-authored-by: v0lumehi <aljic.zijad@gmail.com>
This commit is contained in:
1 parent
3f22526e87
commit
fb20bce70e
17 files changed
+608
-25
No files matched your search
@@ -51,7 +51,7 @@ jobs:
|
||||
run: |
|
||||
mkdir -p logs
|
||||
cd dm/gfx/tests
|
||||
tests="t_dirty_slots t_dirty_race t_tex_layout t_pace t_fstep t_hmap t_cover t_pso_skey t_refl t_rt_range_ro t_present_rescue"
|
||||
tests="t_dirty_slots t_dirty_race t_tex_layout t_pace t_fstep t_hmap t_cover t_pso_skey t_refl t_rt_range_ro t_present_rescue t_gpuprof"
|
||||
make GAME="$GAME" -j3 $tests 2>&1 | tee ../../../logs/gfx-build.log
|
||||
failed=0
|
||||
for t in $tests; do
|
||||
|
||||
@@ -168,6 +168,8 @@ General host changes first needed here; each applies to every game:
|
||||
- **Pipeline bases, hybrid pipelines, the prebuild and the prepare step** (`pso_build_ex`, `hybrid_get`, `pso_prebuild`, `warm_prepare`): [development.md, Hybrid pipelines](../../../docs/development.md#hybrid-pipelines), [Pulling vertex inputs](../../../docs/reference/rendering.md#pulling-vertex-inputs), [the prepare step](../../../docs/development.md#the-prepare-step); measured under [Pipelines on a cold start](#pipelines-on-a-cold-start).
|
||||
- **The pipeline archive made offline** (`dm/gfx/tools/pso_offline.py`, `pso_bundle_open`, `pso_bundle_covers`): [development.md, The pipeline archive made offline](../../../docs/development.md#the-pipeline-archive-made-offline); measured under [Pipelines on a cold start](#pipelines-on-a-cold-start).
|
||||
- **Resolved in synthetic archive review checks:** truncated archive containers, zero-probe coverage, stale archives after library bytes change, and plans whose pairs all require device specialization: [Offline pipeline archive reuse and fallback](../../../docs/reference/shaders.md#offline-pipeline-archive-reuse-and-fallback). Checked with generated libraries on the Mac; no new gameplay or iPhone validation.
|
||||
- **GPU measurement on the iPhone** (`DM_NVN_GPUPROF=every:n`, `DM_AB`, `DM_GPU_CAPTURE`, `dm/tools/gpuprof.py`) and **captures with pipelines built through the device** (`pso4_on`): [05, GPU time on the device](../../../docs/agents/05-debugging.md#gpu-time-on-the-device), [GPU frame captures need pipelines built through the device](../../../docs/reference/shaders.md#gpu-frame-captures-need-pipelines-built-through-the-device).
|
||||
- **Resolved in synthetic profiling review checks:** [Periodic GPU profiles close at frame boundaries](../../../docs/reference/rendering.md#periodic-gpu-profiles-close-at-frame-boundaries). No new gameplay or iPhone validation.
|
||||
- **Hitch dumps and guest thread names** (`DM_HITCH_DUMP`), **heap probes** (`DM_PROBE_HEAP*`), **autorelease leaks**: [05, Scripted input and thread scheduling](../../../docs/agents/05-debugging.md#scripted-input-and-thread-scheduling), [05, Memory growth](../../../docs/agents/05-debugging.md#memory-growth).
|
||||
|
||||
## Open
|
||||
|
||||
@@ -1781,6 +1781,7 @@ NVN(nvnQueuePresentTexture, void, NVNqueue *q, NVNwindow *w, int idx) {
|
||||
} else atomic_store(&g_nvn_ns, 0);
|
||||
g_acq_wait_ns = g_pq_wait_ns = 0;
|
||||
if (f >= 8) { double g = mtl_gpu_ms(f - 8); if (g >= 0) { tpush(3, g); trow(f - 8, "@gpu_ms", g); g_hr[g_hn++ % HRN] = g; } // GPU time is taken 8 frames late (already completed)
|
||||
{ lf_rec *r = &g_lf[(f - 8) % LFN]; if (g >= 0 && r->f == f - 8) mtl_ab_gpu(f - 8, g, r->fr); } // DM_AB phases
|
||||
{ lf_rec *r = &g_lf[(f - 8) % LFN]; // long-frame log (on by default, DM_LONGFRAME=0 turns it off): a line is printed only when the whole frame > 20 ms or GPU > 16.7 ms, and it is clearly above recent conditions
|
||||
static int on = -1; if (on < 0) { const char *e = getenv("DM_LONGFRAME"); on = !(e && !strcmp(e, "0")); }
|
||||
// "Long" is relative to recent conditions: when running steadily at 30 fps (menus / windowless host) or under sustained overload, every frame is > 20 ms; those are not long frames and must not flood the log - a frame has to be 40% above the sliding mean of the last 16 frames to count
|
||||
|
||||
+170
-21
@@ -761,31 +761,56 @@ static inline void m4_end(id e) {
|
||||
// later work, so the next pass's vertex work can overlap this pass's fragments (with the full barriers every pass waited for the previous one to finish completely: about 350 passes a frame in Breath of
|
||||
// the Wild). The next draw pass adds the full consumer barrier when the game called nvnCommandBufferBarrier since the last one (NVN asks for one before results of rendering are read as textures, shader data or
|
||||
// indirect arguments), or when anything other than a draw pass ran in between (compute, copies and uploads keep their full barriers). Only vertex-stage reads of the previous pass's results without a barrier change order
|
||||
static int barrier_game(void) { static int v = -1; if (v < 0) { const char *e = getenv("DM_NVN_BARRIER"); v = e && !strcmp(e, "game"); if (v) MLOG("DM_NVN_BARRIER=game: draw passes are ordered by the game's own barriers (fragment work still has barriers between passes; vertex work may overlap the previous pass's fragments)"); } return v; }
|
||||
// DM_NVN_BARRIER=ab... alternates game and full with the DM_AB phases (measurement)
|
||||
static int sw_mode(const char *name, int dflt); static inline int sw_on(int m);
|
||||
static int barrier_game(void) { static int v = -1; if (v < 0) { const char *e = getenv("DM_NVN_BARRIER"); v = e && !strncmp(e, "ab", 2) ? sw_mode("DM_NVN_BARRIER", 0) : e && !strcmp(e, "game"); if (v == 1) MLOG("DM_NVN_BARRIER=game: draw passes are ordered by the game's own barriers (fragment work still has barriers between passes; vertex work may overlap the previous pass's fragments)"); } return sw_on(v); }
|
||||
void mtl_barrier_stats(uint64_t *skip, uint64_t *full) { *skip = g_bar_skip; *full = g_bar_full; }
|
||||
uint64_t mtl_cut_count(void);
|
||||
// DM_NVN_GPUPROF=first frame[-last frame] (diagnostic): GPU time of every encoder of the main command buffers in those frames. A relaxed timestamp is written into a counter heap when an
|
||||
// encoder begins (before its first draw or dispatch) and when it ends (after its fragment stage); nothing is serialized beyond the barriers the replay already sets, so the frame runs
|
||||
// as usual. Printed as "[gpuprof]" lines (one per encoder, then the frame's sum by kind and size) once the frame's last command buffer completes
|
||||
// as usual. Printed as "[gpuprof]" lines once the frame's last command buffer completes: one per encoder, then a frame line with the render and compute / copy time, the attachment
|
||||
// traffic and the span from the first start to the last end. dm/tools/gpuprof.py sums them by pass shape.
|
||||
// DM_NVN_GPUPROF=every:<n> profiles one frame in every n (frames that are multiples of n), each reported on its own: for a device run whose scene cannot be timed to a frame number.
|
||||
// A render pass line also gives what it loaded and stored of its attachments (KB, the bandwidth ledger's view: DontCare stores are not counted) and the Metal pixel formats of
|
||||
// colour attachment 0 and of the depth / stencil attachment (0: none)
|
||||
enum { GP_MAX = 4096 }; // the largest timestamp heap Metal makes
|
||||
typedef struct { char kind; uint16_t w, h; uint8_t nc, depth, loads; uint32_t draws, seg; uint64_t pass; } gp_lab; // seg: the command buffer (segment) of the submission it is in
|
||||
static id<MTL4CounterHeap> g_gp_heap; static gp_lab g_gp_lab[GP_MAX / 2]; static int g_gp_n, g_gp_state, g_gp_cur = -1; static long g_gp_f0 = -2, g_gp_f1; static uint64_t g_gp_frame;
|
||||
typedef struct { char kind; uint16_t w, h; uint8_t nc, depth, loads; uint32_t draws, seg; uint64_t pass; uint32_t ld_kb, st_kb; uint16_t cfmt, dfmt; } gp_lab; // seg: the command buffer (segment) of the submission it is in
|
||||
static id<MTL4CounterHeap> g_gp_heap; static gp_lab g_gp_lab[GP_MAX / 2]; static int g_gp_n, g_gp_state, g_gp_cur = -1; static long g_gp_f0 = -2, g_gp_f1, g_gp_every; static uint64_t g_gp_frame;
|
||||
static _Atomic int g_gp_busy; // a periodic profile's report has not been printed yet: the heap is still being read
|
||||
static uint64_t g_bw_load, g_bw_store, g_gp_bw_l0, g_gp_bw_s0; // the bandwidth ledger (defined with the pass statistics below) and its values at the last render pass end
|
||||
static uint64_t g_stat_pass, g_stat_draw; static _Atomic uint64_t g_cur_frame; static uint32_t g_seg; static uint32_t g_gp_copies, g_gp_disp, g_gp_ubd; // copies / dispatches encoded (for the compute encoders' labels)
|
||||
static int gp_active(void) {
|
||||
if (__builtin_expect(g_gp_f0 == -1, 1)) return 0;
|
||||
if (g_gp_f0 == -2) { const char *e = getenv("DM_NVN_GPUPROF"); g_gp_f0 = e ? atol(e) : -1; g_gp_f1 = e && strchr(e, '-') ? atol(strchr(e, '-') + 1) : g_gp_f0; if (g_gp_f0 < 0) return 0; }
|
||||
long f = (long)atomic_load(&g_cur_frame); return f >= g_gp_f0 && f <= g_gp_f1;
|
||||
if (g_gp_f0 == -2) { const char *e = getenv("DM_NVN_GPUPROF");
|
||||
if (e && !strncmp(e, "every:", 6)) { g_gp_every = atol(e + 6); g_gp_f0 = g_gp_every > 0 ? 0 : -1; if (g_gp_every > 0) MLOG("DM_NVN_GPUPROF: one frame in every %ld profiled", g_gp_every); }
|
||||
else { g_gp_f0 = e ? atol(e) : -1; g_gp_f1 = e && strchr(e, '-') ? atol(strchr(e, '-') + 1) : g_gp_f0; }
|
||||
if (g_gp_f0 < 0) return 0; }
|
||||
long f = (long)atomic_load(&g_cur_frame);
|
||||
if (g_gp_every > 0) return f > 0 && f % g_gp_every == 0;
|
||||
return f >= g_gp_f0 && f <= g_gp_f1;
|
||||
}
|
||||
static void gp_report(int n, gp_lab *lab, uint64_t frame);
|
||||
static void gp_periodic_finish(void) { // on the submit thread, before the next frame's first encoder can touch the heap
|
||||
if (!g_gp_every || g_gp_state != 1 || g_gp_frame == atomic_load(&g_cur_frame)) return;
|
||||
int n = g_gp_n; gp_lab *lab = malloc(sizeof *lab * (n ? n : 1)); memcpy(lab, g_gp_lab, sizeof *lab * n); uint64_t frame = g_gp_frame;
|
||||
g_gp_state = 2; atomic_store(&g_gp_busy, 1);
|
||||
static MTLSharedEventListener *listener; if (!listener) listener = [MTLSharedEventListener new];
|
||||
// g_fence covers all submissions of the sampled frame. No GPU wait or extra command buffer is needed, including for every:1.
|
||||
[g_ev notifyListener:listener atValue:g_fence block:^(id<MTLSharedEvent> event, uint64_t value) { (void)event; (void)value; gp_report(n, lab, frame); }];
|
||||
}
|
||||
static void gp_begin(id e, char kind, MTL4RenderPassDescriptor *d) { // right after an encoder of the main command buffer is made
|
||||
gp_periodic_finish();
|
||||
if (g_gp_every > 0 && g_gp_state == 2 && !atomic_load(&g_gp_busy)) g_gp_state = 0; // the previous periodic profile has been reported
|
||||
if (!gp_active() || g_gp_state == 2) return;
|
||||
if (!g_gp_heap) { MTL4CounterHeapDescriptor *hd = [MTL4CounterHeapDescriptor new]; hd.type = MTL4CounterHeapTypeTimestamp; hd.count = GP_MAX; NSError *er = nil;
|
||||
g_gp_heap = [g_dev newCounterHeapWithDescriptor:hd error:&er]; if (!g_gp_heap) { MLOG("[RED] GPUPROF: no counter heap: %s", er.description.UTF8String); g_gp_f0 = -1; return; } }
|
||||
if (!g_gp_state) { g_gp_state = 1; g_gp_n = 0; g_gp_frame = atomic_load(&g_cur_frame); [g_gp_heap invalidateCounterRange:NSMakeRange(0, GP_MAX)]; }
|
||||
if (2 * g_gp_n + 2 > GP_MAX) return;
|
||||
gp_lab l = {kind, 0, 0, 0, 0, 0, kind == 'R' ? (uint32_t)g_stat_draw : g_gp_copies, g_seg, g_stat_pass}; if (kind != 'R') { l.w = (uint16_t)g_gp_disp; l.h = (uint16_t)g_gp_ubd; }
|
||||
gp_lab l = {kind, 0, 0, 0, 0, 0, kind == 'R' ? (uint32_t)g_stat_draw : g_gp_copies, g_seg, g_stat_pass, 0, 0, 0, 0}; if (kind != 'R') { l.w = (uint16_t)g_gp_disp; l.h = (uint16_t)g_gp_ubd; }
|
||||
if (d) { for (int i = 0; i < 8; i++) { MTLRenderPassColorAttachmentDescriptor *c = d.colorAttachments[i]; if (!c.texture) continue;
|
||||
l.nc++; l.w = (uint16_t)MAX(c.texture.width >> c.level, 1); l.h = (uint16_t)MAX(c.texture.height >> c.level, 1); l.loads += c.loadAction == MTLLoadActionLoad; }
|
||||
if (!l.nc) l.cfmt = (uint16_t)c.texture.pixelFormat; l.nc++; l.w = (uint16_t)MAX(c.texture.width >> c.level, 1); l.h = (uint16_t)MAX(c.texture.height >> c.level, 1); l.loads += c.loadAction == MTLLoadActionLoad; }
|
||||
MTLRenderPassDepthAttachmentDescriptor *z = d.depthAttachment;
|
||||
if (z.texture || d.stencilAttachment.texture) l.dfmt = (uint16_t)(z.texture ? z.texture : d.stencilAttachment.texture).pixelFormat;
|
||||
if (z.texture) { l.depth = 1; l.w = (uint16_t)MAX(z.texture.width >> z.level, 1); l.h = (uint16_t)MAX(z.texture.height >> z.level, 1); l.loads += z.loadAction == MTLLoadActionLoad; } }
|
||||
g_gp_lab[g_gp_n] = l; g_gp_cur = g_gp_n;
|
||||
if (kind == 'R') [(id<MTL4RenderCommandEncoder>)e writeTimestampWithGranularity:MTL4TimestampGranularityRelaxed afterStage:MTLRenderStageVertex intoHeap:g_gp_heap atIndex:2 * g_gp_n];
|
||||
@@ -794,25 +819,28 @@ static void gp_begin(id e, char kind, MTL4RenderPassDescriptor *d) { // right
|
||||
}
|
||||
static void gp_end(id e) { // right before that encoder ends
|
||||
if (g_gp_cur < 0) return;
|
||||
int k = g_gp_cur; g_gp_cur = -1; if (g_gp_lab[k].kind == 'R') g_gp_lab[k].draws = (uint32_t)g_stat_draw - g_gp_lab[k].draws; else { g_gp_lab[k].draws = g_gp_copies - g_gp_lab[k].draws; g_gp_lab[k].w = (uint16_t)(g_gp_disp - g_gp_lab[k].w); g_gp_lab[k].h = (uint16_t)(g_gp_ubd - g_gp_lab[k].h); }
|
||||
int k = g_gp_cur; g_gp_cur = -1;
|
||||
if (g_gp_lab[k].kind == 'R') { g_gp_lab[k].ld_kb = (uint32_t)((g_bw_load - g_gp_bw_l0) >> 10); g_gp_lab[k].st_kb = (uint32_t)((g_bw_store - g_gp_bw_s0) >> 10); } // since the previous pass end (rp_end); sd_finish has set the stores
|
||||
if (g_gp_lab[k].kind == 'R') g_gp_lab[k].draws = (uint32_t)g_stat_draw - g_gp_lab[k].draws; else { g_gp_lab[k].draws = g_gp_copies - g_gp_lab[k].draws; g_gp_lab[k].w = (uint16_t)(g_gp_disp - g_gp_lab[k].w); g_gp_lab[k].h = (uint16_t)(g_gp_ubd - g_gp_lab[k].h); }
|
||||
if (g_gp_lab[k].kind == 'R') [(id<MTL4RenderCommandEncoder>)e writeTimestampWithGranularity:MTL4TimestampGranularityRelaxed afterStage:MTLRenderStageFragment intoHeap:g_gp_heap atIndex:2 * k + 1];
|
||||
else [(id<MTL4ComputeCommandEncoder>)e writeTimestampWithGranularity:MTL4TimestampGranularityRelaxed intoHeap:g_gp_heap atIndex:2 * k + 1];
|
||||
}
|
||||
static void gp_report(int n, gp_lab *lab, uint64_t frame) { // the frame's last command buffer has completed
|
||||
NSData *r = [g_gp_heap resolveCounterRange:NSMakeRange(0, 2 * n)]; const uint64_t *t = r.bytes; if (!t) { free(lab); return; }
|
||||
double tick_ns = 1e9 / (double)[g_dev queryTimestampFrequency], tot[2] = {0}, span = 0; uint64_t t0 = 0, t1 = 0;
|
||||
NSData *r = [g_gp_heap resolveCounterRange:NSMakeRange(0, 2 * n)]; const uint64_t *t = r.bytes; if (!t) { free(lab); atomic_store(&g_gp_busy, 0); return; }
|
||||
double tick_ns = 1e9 / (double)[g_dev queryTimestampFrequency], tot[2] = {0}, span = 0; uint64_t t0 = 0, t1 = 0, ld = 0, st = 0; int np = 0;
|
||||
for (int i = 0; i < n; i++) { uint64_t a = t[2 * i], b = t[2 * i + 1]; if (!a || !b || b < a) continue;
|
||||
double us = (b - a) * tick_ns / 1e3; const gp_lab *l = &lab[i]; tot[l->kind != 'R'] += us;
|
||||
if (!t0 || a < t0) t0 = a; if (b > t1) t1 = b;
|
||||
if (l->kind == 'R') MLOG("[gpuprof] F%llu %4d %8.1f us render pass %llu %ux%u colors %u depth %u loads %u draws %u start %+.1f seg %u", (unsigned long long)frame, i, us, (unsigned long long)l->pass, l->w, l->h, l->nc, l->depth, l->loads, l->draws, (a - t[0]) * tick_ns / 1e3, l->seg);
|
||||
if (l->kind == 'R') { np++; ld += l->ld_kb; st += l->st_kb;
|
||||
MLOG("[gpuprof] F%llu %4d %8.1f us render pass %llu %ux%u colors %u depth %u loads %u draws %u start %+.1f seg %u load %u KB store %u KB fmt %u/%u", (unsigned long long)frame, i, us, (unsigned long long)l->pass, l->w, l->h, l->nc, l->depth, l->loads, l->draws, (a - t[0]) * tick_ns / 1e3, l->seg, l->ld_kb, l->st_kb, l->cfmt, l->dfmt); }
|
||||
else MLOG("[gpuprof] F%llu %4d %8.1f us compute / copy after pass %llu start %+.1f seg %u copies %u (uniform updates %u) dispatches %u", (unsigned long long)frame, i, us, (unsigned long long)l->pass, (a - t[0]) * tick_ns / 1e3, l->seg, l->draws, l->h, l->w); }
|
||||
span = (t1 - t0) * tick_ns / 1e3;
|
||||
MLOG("[gpuprof] frame %llu: render %.2f ms, compute / copy %.2f ms over %d encoders, first start to last end %.2f ms", (unsigned long long)frame, tot[0] / 1e3, tot[1] / 1e3, n, span / 1e3);
|
||||
free(lab);
|
||||
MLOG("[gpuprof] frame %llu: render %.2f ms, compute / copy %.2f ms over %d encoders (%d render passes, attachments load %.1f MB store %.1f MB), first start to last end %.2f ms", (unsigned long long)frame, tot[0] / 1e3, tot[1] / 1e3, n, np, ld / 1024.0, st / 1024.0, span / 1e3);
|
||||
free(lab); atomic_store(&g_gp_busy, 0);
|
||||
}
|
||||
static inline id<MTL4RenderCommandEncoder> enc_r_begin_pass(MTL4RenderPassDescriptor *d) { // the draw passes (rp_begin_ex); see barrier_game
|
||||
id<MTL4RenderCommandEncoder> e = [g_cb renderCommandEncoderWithDescriptor:d];
|
||||
if (g_last_end_relaxed && !g_game_barrier) g_bar_skip++;
|
||||
if (g_last_end_relaxed && !g_game_barrier && barrier_game()) g_bar_skip++;
|
||||
else { [e barrierAfterQueueStages:MTLStageAll beforeStages:MTLStageAll visibilityOptions:MTL4VisibilityOptionDevice]; g_bar_full++; }
|
||||
g_game_barrier = 0;
|
||||
[e setArgumentTable:g_vt atStages:MTLRenderStageVertex]; [e setArgumentTable:g_ft atStages:MTLRenderStageFragment]; gp_begin(e, 'R', d); return e;
|
||||
@@ -1238,7 +1266,57 @@ static int ub_skip(const char *key) { // Whether this phase should drop draws
|
||||
for (int i = 0; i < g_ub_nk[uc]; i++) { const char *k = g_ub_keys[uc][i]; if (k[0] == '@') continue; if (k[0] == '*' || !strncmp(key, k, strlen(k))) return 1; }
|
||||
return 0;
|
||||
}
|
||||
void mtl_set_frame(uint64_t f) { atomic_store(&g_cur_frame, f); if (g_ub_n) ub_frame(f); }
|
||||
static long ab_len(void); static void ab_frame(uint64_t f);
|
||||
// DM_GPU_CAPTURE=<frame>[:<frames>] (diagnostic): a Metal GPU trace of those frames (default 1) for Xcode's Metal debugger (per-draw cost, shader profiler), or DM_GPU_CAPTURE=gpu:<ms>[:<after frame>]
|
||||
// of one frame in the first scene, after that frame, whose GPU time passes <ms> in 60 frames in a row (a single long frame in a light scene fired the first iPhone capture). Read again
|
||||
// when it changes, so the Mac's DM_CTL "env DM_GPU_CAPTURE=..." can set it while the game runs. iOS needs a build with MetalCaptureEnabled (DM_METAL_CAPTURE=1 when the project is
|
||||
// made), the Mac MTL_CAPTURE_ENABLED=1 in the environment. It captures the Metal 4 queue (Metal refuses to capture a Metal 4 device), so the old-queue helpers (present, some uploads)
|
||||
// are not in it. The trace is dm_<date>-<time>_f<frame>.gputrace in DM_GPU_CAPTURE_DIR, by default gpu_captures/ in the working directory (the app's Documents on iOS, the run folder
|
||||
// on the Mac). A trace takes 1.5-2 GB, so before each capture that folder alone is pruned: of its dm_*.gputrace entries the newest DM_GPU_CAPTURE_KEEP - 1 stay (default 2 with the new
|
||||
// one); nothing outside it is removed
|
||||
static long g_cap_f0 = -2, g_cap_n; static int g_cap_on;
|
||||
static NSString *gpu_capture_dir(void) {
|
||||
const char *e = getenv("DM_GPU_CAPTURE_DIR"); NSString *dir;
|
||||
if (e && *e) dir = @(e); else { char cwd[1024]; if (!getcwd(cwd, sizeof cwd)) strcpy(cwd, "."); dir = [@(cwd) stringByAppendingPathComponent:@"gpu_captures"]; }
|
||||
NSError *err = nil;
|
||||
if (![NSFileManager.defaultManager createDirectoryAtPath:dir withIntermediateDirectories:YES attributes:nil error:&err]) { MLOG("[RED] DM_GPU_CAPTURE: cannot make the folder %s: %s", dir.UTF8String, err.localizedDescription.UTF8String); return nil; }
|
||||
return dir;
|
||||
}
|
||||
static void gpu_capture_prune(NSString *dir) { // only dm_*.gputrace entries directly in the capture folder; the newest DM_GPU_CAPTURE_KEEP - 1 stay
|
||||
const char *e = getenv("DM_GPU_CAPTURE_KEEP"); long keep = e ? atol(e) : 2; if (keep < 1) keep = 1;
|
||||
NSFileManager *fm = NSFileManager.defaultManager; NSMutableArray<NSURL *> *traces = [NSMutableArray array];
|
||||
for (NSURL *u in [fm contentsOfDirectoryAtURL:[NSURL fileURLWithPath:dir isDirectory:YES] includingPropertiesForKeys:@[NSURLContentModificationDateKey] options:0 error:nil]) {
|
||||
NSString *n = u.lastPathComponent; if ([n hasPrefix:@"dm_"] && [n hasSuffix:@".gputrace"]) [traces addObject:u]; }
|
||||
[traces sortUsingComparator:^NSComparisonResult(NSURL *a, NSURL *b) { NSDate *da = nil, *db = nil;
|
||||
[a getResourceValue:&da forKey:NSURLContentModificationDateKey error:nil]; [b getResourceValue:&db forKey:NSURLContentModificationDateKey error:nil];
|
||||
return [db ?: NSDate.distantPast compare:da ?: NSDate.distantPast]; }]; // newest first
|
||||
for (NSUInteger i = (NSUInteger)keep - 1; i < traces.count; i++) if ([fm removeItemAtURL:traces[i] error:nil]) MLOG("DM_GPU_CAPTURE: removed %s (older captures beyond DM_GPU_CAPTURE_KEEP=%ld)", traces[i].lastPathComponent.UTF8String, keep);
|
||||
}
|
||||
static void gpu_capture_frame(uint64_t f) {
|
||||
static char last[32]; // read again when it changes
|
||||
{ const char *e = getenv("DM_GPU_CAPTURE"); if (!g_cap_on && e && strncmp(e, last, sizeof last - 1)) { snprintf(last, sizeof last, "%s", e); g_cap_f0 = -2; } }
|
||||
static double gpu_thr; static long after; static int over;
|
||||
if (g_cap_f0 == -2) { const char *e = getenv("DM_GPU_CAPTURE"); gpu_thr = 0; over = 0;
|
||||
if (e && !strncmp(e, "gpu:", 4)) { gpu_thr = atof(e + 4); const char *c = strchr(e + 4, ':'); after = c ? atol(c + 1) : 0; g_cap_n = 1; g_cap_f0 = gpu_thr > 0 ? LONG_MAX : -1; // armed: the frame is not known yet
|
||||
if (gpu_thr > 0) MLOG("DM_GPU_CAPTURE: the first frame after frame %ld that follows 60 frames in a row with more than %.1f ms of GPU time is captured", after, gpu_thr); }
|
||||
else { g_cap_f0 = e ? atol(e) : -1; g_cap_n = e && strchr(e, ':') ? atol(strchr(e, ':') + 1) : 1; if (g_cap_n < 1) g_cap_n = 1; if (g_cap_f0 <= 0) g_cap_f0 = -1; } }
|
||||
if (g_cap_f0 < 0) return;
|
||||
if (gpu_thr > 0 && !g_cap_on && f > 8 && (long)f >= after) { double g = mtl_gpu_ms(f - 8); over = g >= gpu_thr ? over + 1 : g >= 0 ? 0 : over; if (over >= 60) g_cap_f0 = (long)f; }
|
||||
MTLCaptureManager *m = [MTLCaptureManager sharedCaptureManager];
|
||||
if (!g_cap_on && f == (uint64_t)g_cap_f0) {
|
||||
g_cap_f0 = -1; // one capture per setting: a failure below does not retry every frame
|
||||
if (![m supportsDestination:MTLCaptureDestinationGPUTraceDocument]) { MLOG("[RED] DM_GPU_CAPTURE: this build cannot write GPU traces (iOS: MetalCaptureEnabled, a build made with DM_METAL_CAPTURE=1; Mac: MTL_CAPTURE_ENABLED=1)"); return; }
|
||||
NSString *dir = gpu_capture_dir(); if (!dir) return;
|
||||
gpu_capture_prune(dir);
|
||||
time_t now = time(NULL); struct tm tm; localtime_r(&now, &tm); char ts[32]; strftime(ts, sizeof ts, "%Y%m%d-%H%M%S", &tm);
|
||||
NSString *path = [dir stringByAppendingPathComponent:[NSString stringWithFormat:@"dm_%s_f%llu.gputrace", ts, (unsigned long long)f]];
|
||||
MTLCaptureDescriptor *d = [MTLCaptureDescriptor new]; d.captureObject = g_q4 ? (id)g_q4 : (id)g_dev; d.destination = MTLCaptureDestinationGPUTraceDocument; d.outputURL = [NSURL fileURLWithPath:path];
|
||||
NSError *err = nil;
|
||||
if ([m startCaptureWithDescriptor:d error:&err]) { g_cap_on = 1; g_cap_f0 = (long)f; MLOG("DM_GPU_CAPTURE: capturing frames %llu to %llu into %s", (unsigned long long)f, (unsigned long long)(f + g_cap_n - 1), path.UTF8String); }
|
||||
else MLOG("[RED] DM_GPU_CAPTURE: the capture did not start: %s", err.localizedDescription.UTF8String);
|
||||
} else if (g_cap_on && f >= (uint64_t)g_cap_f0 + (uint64_t)g_cap_n) { [m stopCapture]; g_cap_on = 0; g_cap_f0 = -1; gpu_thr = 0; MLOG("DM_GPU_CAPTURE: capture stopped at frame %llu (the trace is written in the background)", (unsigned long long)f); }
|
||||
}
|
||||
void mtl_set_frame(uint64_t f) { atomic_store(&g_cur_frame, f); if (g_ub_n) ub_frame(f); if (ab_len()) ab_frame(f); gpu_capture_frame(f); }
|
||||
// GPU timing registration: gpu_tag_begin(frame) before commit, gpu_tag_done(frame, GPU start, GPU end) on completion (seconds on the CACurrentMediaTime base).
|
||||
// Old-queue command buffers go through gpu_tag_f; the Metal 4 main submission backfills in the feedback of mtl_sub_commit (when switching to Metal 4 all the call sites were lost and the GPU column of the timing line became empty)
|
||||
static void gpu_tag_begin(uint64_t f) {
|
||||
@@ -1313,7 +1391,7 @@ uint64_t mtl_sub_commit(void) {
|
||||
}];
|
||||
void arena_commit(uint64_t fence); arena_commit(fence);
|
||||
res_commit();
|
||||
if (g_gp_state == 1 && !gp_active()) { int gn = g_gp_n; gp_lab *gl = malloc(sizeof(gp_lab) * (gn ? gn : 1)); memcpy(gl, g_gp_lab, sizeof(gp_lab) * gn); uint64_t gf = g_gp_frame; g_gp_state = 2;
|
||||
if (g_gp_state == 1 && !gp_active()) { int gn = g_gp_n; gp_lab *gl = malloc(sizeof(gp_lab) * (gn ? gn : 1)); memcpy(gl, g_gp_lab, sizeof(gp_lab) * gn); uint64_t gf = g_gp_frame; g_gp_state = 2; atomic_store(&g_gp_busy, 1);
|
||||
[o addFeedbackHandler:^(id<MTL4CommitFeedback> f) { (void)f; gp_report(gn, gl, gf); }]; }
|
||||
[g_cb endCommandBuffer];
|
||||
rec_commit(g_cb, o);
|
||||
@@ -2308,15 +2386,20 @@ static uint64_t g_stat_draw, g_stat_pass, g_bw_load, g_bw_store, g_pass_full_rw,
|
||||
// DM_NVN_PASSDUMP: records pass attachments / samples / presents one by one (textures by serial) for offline data-flow analysis; the pass numbers of P / D / R / S lines agree (= g_stat_pass after the pass is opened)
|
||||
// DM_NVN_PASSDUMP=frame number, or start-end (inclusive at both ends)
|
||||
static int g_kd_force; // the draw DM_NVN_KEYDUMP matched: force the per-binding records on (see kd_draw)
|
||||
static _Atomic long g_pd_a0 = -2, g_pd_a1; // the frames dumped (inclusive); -2 = DM_NVN_PASSDUMP not read yet
|
||||
static _Atomic long g_pd_a0 = -2, g_pd_a1; // the frames dumped (inclusive); -2 = DM_NVN_PASSDUMP not read yet, -3 = DM_NVN_PASSDUMP=every:<n>
|
||||
static long g_pd_every;
|
||||
static inline int passdump(void) {
|
||||
if (g_kd_force) return 1;
|
||||
#ifdef NVN_RT_RANGE_TEST
|
||||
if (g_rr_checking) return 0;
|
||||
#endif
|
||||
if (__builtin_expect(g_pd_a0 == -1, 1)) return 0; // off (the usual case): answered first, it is asked for every binding of every draw
|
||||
if (g_pd_a0 == -2) { const char *e = getenv("DM_NVN_PASSDUMP"); g_pd_a1 = e && strchr(e, '-') ? atol(strchr(e, '-') + 1) : e ? atol(e) : -1; g_pd_a0 = e ? atol(e) : -1; }
|
||||
long f = (long)atomic_load(&g_cur_frame), a0 = g_pd_a0; return a0 >= 0 && f >= a0 && f <= g_pd_a1;
|
||||
if (g_pd_a0 == -2) { const char *e = getenv("DM_NVN_PASSDUMP");
|
||||
if (e && !strncmp(e, "every:", 6)) { g_pd_every = atol(e + 6); g_pd_a1 = -1; g_pd_a0 = g_pd_every > 0 ? -3 : -1; } // one frame in every n, halfway between two DM_NVN_GPUPROF=every:n frames
|
||||
else { g_pd_a1 = e && strchr(e, '-') ? atol(strchr(e, '-') + 1) : e ? atol(e) : -1; g_pd_a0 = e ? atol(e) : -1; } }
|
||||
long f = (long)atomic_load(&g_cur_frame), a0 = g_pd_a0;
|
||||
if (a0 == -3) return f > 0 && f % g_pd_every == g_pd_every / 2;
|
||||
return a0 >= 0 && f >= a0 && f <= g_pd_a1;
|
||||
}
|
||||
// The next n frames' passes, on request (the Mac's DM_CTL "passdump n", hle_hid.c): for a scene that a fixed DM_NVN_PASSDUMP frame range cannot be timed to
|
||||
void dm_gfx_passdump_next(long n) { long f = (long)atomic_load(&g_cur_frame); g_pd_a1 = f + n; g_pd_a0 = f + 1; }
|
||||
@@ -2484,6 +2567,68 @@ static int udc_on(void) {
|
||||
// so the inference would miss readers - e.g. deciding an attachment is never read afterwards and not storing it. Turn them back on once they recognize bindless readers.
|
||||
static int tbdr_on(void) { static int v = -1; if (v < 0) { const char *e = getenv("DM_NVN_TBDR"); v = e && !strcmp(e, "1"); if (!v) MLOG("TBDR optimizations off by default (this game uses bindless textures; DM_NVN_TBDR=1 turns them on)"); } return v; }
|
||||
static int rt_range_on(void) { static int v = -1; if (v < 0) { const char *e=getenv("DM_NVN_RT_RANGE"); v=e && !strcmp(e,"1"); } return v; } // Narrow candidate, off by default
|
||||
// ---------- In-process A/B phases (DM_AB, measurement) ----------
|
||||
// DM_AB=<frames> splits the run into phases of that many frames (frame f is in phase f / frames) and alternates the switches whose value is ab (sw_mode; DM_NVN_BARRIER=ab so far):
|
||||
// ab = on in every second phase (phase 0 with all of them off), ab:<k>[,<k>...]/<n> = on in the phases whose number modulo n is one of the k (four configurations of two switches: one
|
||||
// ab:1,3/4, the other ab:2,3/4). Both configurations then run in the same process, scene and thermal state, which separate runs on a phone cannot give. A switch reads its mode once
|
||||
// (sw_mode) and asks sw_on at each use; one that must stay the same over a pass latches it when the pass begins
|
||||
static _Atomic long g_ab_phase; static long g_ab_len = -1;
|
||||
static long ab_len(void) { if (g_ab_len < 0) { const char *e = getenv("DM_AB"); g_ab_len = e ? atol(e) : 0; if (g_ab_len < 0) g_ab_len = 0; if (g_ab_len) MLOG("DM_AB: switches set to ab alternate every %ld frames (phase 0 with all of them off)", g_ab_len); } return g_ab_len; }
|
||||
enum { SW_MAX = 8 }; static const char *g_sw_name[SW_MAX]; static int g_sw_mode[SW_MAX], g_sw_n;
|
||||
static inline int sw_on_at(int m, long ph) { if (m < 2) return m; int n = (m - 2) & 15, mask = (m - 2) >> 4; return mask >> (ph % n) & 1; }
|
||||
// The mode of switch <name>: 0 off, 1 on, 2 + n + 16 * mask = on in the phases whose number modulo n is in mask; ab without DM_AB is off
|
||||
static int sw_mode(const char *name, int dflt) {
|
||||
const char *e = getenv(name); int m = dflt, mask = 2, n = 2;
|
||||
if (e && !strncmp(e, "ab", 2)) {
|
||||
if (e[2] == ':') { const char *sl = strchr(e, '/'); int nn = sl ? atoi(sl + 1) : 0, mk = 0;
|
||||
for (const char *q = e + 3; sl && q < sl; ) { int k = atoi(q); if (k >= 0 && k < 15) mk |= 1 << k; while (q < sl && *q != ',') q++; if (q < sl) q++; }
|
||||
if (nn >= 2 && nn <= 15 && mk && mk < (1 << nn)) { mask = mk; n = nn; } }
|
||||
m = ab_len() ? 2 + n + 16 * mask : 0;
|
||||
if (!ab_len()) MLOG("[RED] %s=%s needs DM_AB=<frames>: the switch is off", name, e); }
|
||||
else if (e) m = atoi(e) ? 1 : 0;
|
||||
if (m >= 2) MLOG("%s: on in the DM_AB phases whose number modulo %d is in the set %#x", name, n, mask);
|
||||
if (g_sw_n < SW_MAX) { g_sw_name[g_sw_n] = name; g_sw_mode[g_sw_n++] = m; }
|
||||
return m;
|
||||
}
|
||||
static inline int sw_on(int m) { return sw_on_at(m, atomic_load_explicit(&g_ab_phase, memory_order_relaxed)); }
|
||||
// Each phase is reported once its frames' GPU times have arrived (8 frames late) as an [ab] line: the switches on in it, GPU time and whole frame time (p50 / p90 / mean over the phase
|
||||
// without its first quarter, while the GPU clock and the frame step settle), and attachment traffic and render passes per frame (the bandwidth ledger)
|
||||
enum { AB_MAXF = 4096 };
|
||||
static float g_ab_gpu[AB_MAXF], g_ab_fr[AB_MAXF]; static int g_ab_nf; static long g_ab_ph = -1; static uint64_t g_ab_bw0[2], g_ab_pass0, g_ab_f0;
|
||||
static uint64_t g_ab_bw1[2], g_ab_pass1, g_ab_f1; // the counters at the switch to the current phase (taken in ab_frame), copied to *0 when the previous phase is reported
|
||||
static int flt_cmp(const void *a, const void *b) { float x = *(const float *)a, y = *(const float *)b; return x < y ? -1 : x > y; }
|
||||
static void ab_frame(uint64_t f) { // frame f begins (mtl_set_frame): the phase follows the frame number
|
||||
long ph = (long)(f / (uint64_t)g_ab_len);
|
||||
if (atomic_load(&g_ab_phase) != ph || f % (uint64_t)g_ab_len == 0) { g_ab_bw1[0] = g_bw_load; g_ab_bw1[1] = g_bw_store; g_ab_pass1 = g_stat_pass; g_ab_f1 = f; }
|
||||
atomic_store(&g_ab_phase, ph);
|
||||
}
|
||||
static void ab_report(long ph) {
|
||||
int n = g_ab_nf, skip = n / 4, m = n - skip; if (m < 10) return;
|
||||
float *g = malloc(sizeof(float) * (size_t)m), *fr = malloc(sizeof(float) * (size_t)m); double gs = 0, fs = 0;
|
||||
for (int i = 0; i < m; i++) { g[i] = g_ab_gpu[skip + i]; fr[i] = g_ab_fr[skip + i]; gs += g[i]; fs += fr[i]; }
|
||||
qsort(g, (size_t)m, sizeof *g, flt_cmp); qsort(fr, (size_t)m, sizeof *fr, flt_cmp);
|
||||
double nf = g_ab_f1 > g_ab_f0 ? (double)(g_ab_f1 - g_ab_f0) : 1;
|
||||
char on[160] = ""; size_t o = 0;
|
||||
for (int i = 0; i < g_sw_n && o < sizeof on; i++) if (g_sw_mode[i] >= 2 && sw_on_at(g_sw_mode[i], ph)) {
|
||||
const char *nm = g_sw_name[i]; if (!strncmp(nm, "DM_NVN_", 7)) nm += 7; else if (!strncmp(nm, "DM_", 3)) nm += 3;
|
||||
o += (size_t)snprintf(on + o, sizeof on - o, "%s%s", o ? "," : "", nm); }
|
||||
MLOG("[ab] phase %ld %s: %d frames, GPU p50 %.2f / p90 %.2f / mean %.2f ms, frame p50 %.2f / p90 %.2f / mean %.2f ms; per frame: attachments load %.0f MB store %.0f MB, passes %.1f",
|
||||
ph, o ? on : "base", m, g[m / 2], g[m * 9 / 10], gs / m, fr[m / 2], fr[m * 9 / 10], fs / m,
|
||||
(g_ab_bw1[0] - g_ab_bw0[0]) / nf / 1048576.0, (g_ab_bw1[1] - g_ab_bw0[1]) / nf / 1048576.0, (g_ab_pass1 - g_ab_pass0) / nf);
|
||||
free(g); free(fr);
|
||||
}
|
||||
// Once per frame with that frame's GPU time and whole frame time (hle_nvn.c, 8 frames late); the phase is the one frame f ran in
|
||||
void mtl_ab_gpu(uint64_t f, double gpu_ms, double frame_ms) {
|
||||
if (!ab_len()) return;
|
||||
long ph = (long)(f / (uint64_t)g_ab_len);
|
||||
if (ph != g_ab_ph) {
|
||||
if (g_ab_ph >= 0) ab_report(g_ab_ph);
|
||||
g_ab_ph = ph; g_ab_nf = 0;
|
||||
memcpy(g_ab_bw0, g_ab_bw1, sizeof g_ab_bw0); g_ab_pass0 = g_ab_pass1; g_ab_f0 = g_ab_f1;
|
||||
}
|
||||
if (g_ab_nf < AB_MAXF) { g_ab_gpu[g_ab_nf] = (float)gpu_ms; g_ab_fr[g_ab_nf] = (float)frame_ms; g_ab_nf++; }
|
||||
}
|
||||
|
||||
static uint64_t g_sd_dead_bytes, g_sd_n_dead, g_sd_n_all;
|
||||
// ---------- Cross-submission attachment validity ledger ----------
|
||||
// Entry = subresource (texture serial, level, layer) + state, surviving across submissions:
|
||||
@@ -2584,7 +2729,8 @@ static void rp_end(void) { if (g_enc) { AP_B;
|
||||
#ifdef NVN_RT_RANGE_TEST
|
||||
int ranged=g_rt_range_active && !g_rt_range_pending;
|
||||
#endif
|
||||
sd_finish(); enc_r_end_pass(g_enc); zskip_commit_clears(); g_enc = nil; g_rt_merged = 0; g_rt_range_active = g_rt_range_pending = 0; pg_end_render(); ts_after(); ms_after(); if (g_lp.count) lp_finish(); fz_end();
|
||||
sd_finish(); enc_r_end_pass(g_enc); g_gp_bw_l0 = g_bw_load; g_gp_bw_s0 = g_bw_store; // the profile's per-pass ledger counts from the previous pass end, profiled or not
|
||||
zskip_commit_clears(); g_enc = nil; g_rt_merged = 0; g_rt_range_active = g_rt_range_pending = 0; pg_end_render(); ts_after(); ms_after(); if (g_lp.count) lp_finish(); fz_end();
|
||||
if (g_nubd && g_nubd >= ubd_lazy()) ubd_flush(); // the inline updates deferred in this pass, in order (see mtl_sub_update); across passes they wait for the next copy or dispatch (blit_raw)
|
||||
if (g_nbcrt) bcrt_flush(); // blocks drawn into shadows go back into their compressed textures
|
||||
#ifdef NVN_RT_RANGE_TEST
|
||||
@@ -4473,6 +4619,9 @@ static int pso4_on(void) {
|
||||
v = !(e && !strcmp(e, "0"));
|
||||
if (!v) MLOG("DM_PSO_MTL4=0: render pipelines are built through the MTLDevice (no bases, no pipeline archive)");
|
||||
#endif
|
||||
// Metal cannot capture pipelines made from bases ("Capturing Render pipeline specialization is not supported"), and its Metal 4 → 3 conversion for the capture layer
|
||||
// crashes on the archives: a run that may capture GPU frames (DM_GPU_CAPTURE, MTL_CAPTURE_ENABLED) builds its pipelines through the MTLDevice
|
||||
if (v && (getenv("DM_GPU_CAPTURE") || getenv("MTL_CAPTURE_ENABLED"))) { v = 0; MLOG("render pipelines through the MTLDevice in a run that may capture GPU frames (DM_GPU_CAPTURE / MTL_CAPTURE_ENABLED)"); }
|
||||
}
|
||||
return v;
|
||||
}
|
||||
|
||||
@@ -193,6 +193,7 @@ void mtl_set_tex_pool_n(int n); // Texture descriptor
|
||||
void mtl_set_frame(uint64_t f);
|
||||
void mtl_ub_present(double iv_ms); // Same-process alternating measurement (DM_NVN_UB): the present thread reports the actual present interval every frame
|
||||
double mtl_gpu_ms(uint64_t f);
|
||||
void mtl_ab_gpu(uint64_t f, double gpu_ms, double frame_ms); // DM_AB phases (nvn_mtl.m)
|
||||
void mtl_sub_index(const uint64_t *h, int n); // Start of submission: build the store lookahead index in replay order (nvn_mtl.m)
|
||||
void xv_test_counts(int *dc, int *viol);
|
||||
int mtl_gpu_span(uint64_t f, uint64_t *t0, uint64_t *t1); // The frame's earliest GPUStart / latest GPUEnd (mach absolute time, ns); returns 0 if not all complete or there is no GPU time
|
||||
|
||||
@@ -55,6 +55,8 @@ t_zskip.dSYM/
|
||||
t_xv
|
||||
t_xv.dSYM/
|
||||
t_ub
|
||||
t_gpuprof
|
||||
t_gpuprof.dSYM/
|
||||
t_ub.dSYM/
|
||||
t_vbuf
|
||||
t_vbuf.dSYM/
|
||||
|
||||
@@ -112,6 +112,8 @@ t_xv: t_xv.m $(MTL_T_DEP)
|
||||
clang $(CFLAGS) -fobjc-arc -o $@ t_xv.m $(MTL_T_SRC) $(FW)
|
||||
t_ub: t_ub.m $(MTL_T_DEP)
|
||||
clang $(CFLAGS) -fobjc-arc -o $@ t_ub.m $(MTL_T_SRC) $(FW)
|
||||
t_gpuprof: t_gpuprof.m $(MTL_T_DEP)
|
||||
clang $(CFLAGS) -fobjc-arc -o $@ t_gpuprof.m $(MTL_T_SRC) $(FW)
|
||||
t_vbuf: t_vbuf.m $(MTL_T_DEP)
|
||||
clang $(CFLAGS) -fobjc-arc -o $@ t_vbuf.m $(MTL_T_SRC) $(FW)
|
||||
t_geometry: t_geometry.m $(MTL_T_DEP)
|
||||
|
||||
@@ -0,0 +1,69 @@
|
||||
// Periodic profiling closes at a frame boundary even when every frame is selected.
|
||||
// Fake counter / event objects exercise production heap ownership without a GPU.
|
||||
#include "../nvn/nvn_mtl.m"
|
||||
void *front_metal_layer(void) { return NULL; }
|
||||
module_t *module_of(const void *p) { (void)p; return NULL; }
|
||||
module_t g_mod[MAX_MOD]; int g_nmod;
|
||||
void svc_thread_dump(void) {}
|
||||
uint64_t now_ns(void) { return bp_now(); }
|
||||
static int checks, failed;
|
||||
#define CHECK(c, label) do { checks++; if (!(c)) { failed++; fprintf(stderr, "FAIL: %s\n", label); } } while (0)
|
||||
|
||||
@interface ProfileHeap : NSObject
|
||||
@property int invalidations, resolutions;
|
||||
@end
|
||||
@implementation ProfileHeap
|
||||
- (void)invalidateCounterRange:(NSRange)range { (void)range; _invalidations++; }
|
||||
- (NSData *)resolveCounterRange:(NSRange)range {
|
||||
_resolutions++; uint64_t values[GP_MAX];
|
||||
for (NSUInteger i = 0; i < range.length; i++) values[i] = 1000 + 100 * i;
|
||||
return [NSData dataWithBytes:values length:range.length * sizeof *values];
|
||||
}
|
||||
@end
|
||||
@interface ProfileDevice : NSObject
|
||||
@end
|
||||
@implementation ProfileDevice
|
||||
- (uint64_t)queryTimestampFrequency { return 1000000000; }
|
||||
@end
|
||||
@interface ProfileEvent : NSObject
|
||||
@property(copy) MTLSharedEventNotificationBlock notification;
|
||||
@property uint64_t value;
|
||||
@property int registrations;
|
||||
@end
|
||||
@implementation ProfileEvent
|
||||
- (void)notifyListener:(MTLSharedEventListener *)listener atValue:(uint64_t)value block:(MTLSharedEventNotificationBlock)block {
|
||||
(void)listener; CHECK(!_notification, "a pending report keeps exclusive ownership of the heap");
|
||||
_notification = block; _value = value; _registrations++;
|
||||
}
|
||||
- (void)complete {
|
||||
MTLSharedEventNotificationBlock block = _notification; _notification = nil;
|
||||
CHECK(block != nil, "the sampled frame registered a completion report");
|
||||
if (block) block((id)self, _value);
|
||||
}
|
||||
@end
|
||||
|
||||
int main(void) { @autoreleasepool {
|
||||
ProfileHeap *heap = [ProfileHeap new]; ProfileEvent *event = [ProfileEvent new];
|
||||
g_gp_heap = (id)heap; g_dev = (id)[ProfileDevice new]; g_ev = (id)event;
|
||||
setenv("DM_NVN_GPUPROF", "every:1", 1);
|
||||
atomic_store(&g_cur_frame, 0); gp_begin(nil, 'C', nil); CHECK(!g_gp_state, "frame zero is not profiled");
|
||||
for (uint64_t frame = 1; frame <= 3; frame++) {
|
||||
atomic_store(&g_cur_frame, frame); gp_begin(nil, 'C', nil); gp_end(nil);
|
||||
CHECK(g_gp_state == 1 && g_gp_frame == frame && g_gp_n == 1, "a fresh sample belongs only to its selected frame");
|
||||
gp_begin(nil, 'C', nil); gp_end(nil);
|
||||
CHECK(g_gp_n == 2, "all encoders in the frame share its sample");
|
||||
g_fence = frame * 10;
|
||||
atomic_store(&g_cur_frame, frame + 1); gp_begin(nil, 'C', nil);
|
||||
CHECK(g_gp_state == 2 && atomic_load(&g_gp_busy), "the next frame closes the prior sample even for every:1");
|
||||
CHECK(event.value == g_fence, "report waits for every committed segment of the sampled frame");
|
||||
CHECK(g_gp_n == 2 && heap.invalidations == frame, "no following frame overwrites pending timestamps");
|
||||
[event complete];
|
||||
CHECK(!atomic_load(&g_gp_busy) && heap.resolutions == frame, "completion resolves the sampled frame once and releases the heap");
|
||||
}
|
||||
// Sparse periodic selection also closes without waiting for a later unprofiled commit.
|
||||
g_gp_every = 5; g_gp_state = 0;
|
||||
atomic_store(&g_cur_frame, 5); gp_begin(nil, 'C', nil); gp_end(nil); g_fence = 50;
|
||||
atomic_store(&g_cur_frame, 6); gp_begin(nil, 'C', nil); [event complete];
|
||||
CHECK(event.registrations == 4 && heap.resolutions == 4, "sparse and consecutive selection both report per frame");
|
||||
printf("t_gpuprof: %d checks, %d failed\n", checks, failed); return failed != 0;
|
||||
} }
|
||||
@@ -8,6 +8,7 @@
|
||||
# AOC=add-on content directory (default $W/data/aoc; when it exists it goes to DmIOS.app/aoc/<index>/; an empty string = none), GFXAPI=nvn / vulkan (default: by the shader libraries in MSL_IOS)
|
||||
# The app name is the game name in the base NSP's control data ($W/data/v0/control.nacp, else the one next to the RomFS), the app version is the display version in the packed game's control data (the one next to the RomFS:
|
||||
# nx_extract saves the update's there when an update is packed, else the base game's), the bundle ID is org.nxnative.<base game title ID in lowercase> (DM_DISPLAY_NAME / DM_APP_VERSION / DM_BUNDLE_ID override them);
|
||||
# DM_METAL_CAPTURE=1 makes a development build that can write GPU frame captures (MetalCaptureEnabled in Info.plist, for the host's DM_GPU_CAPTURE switch);
|
||||
# DM_SHOW_FPS=1 turns the frame-rate counter on (DMShowFPS in Info.plist; DM_SHOW_FPS in the app's Documents/env.txt overrides it on the phone);
|
||||
# DM_LANG=<language code> is the game language (DMLanguage in Info.plist, default en-US; DM_LANG in the app's Documents/env.txt overrides it on the phone);
|
||||
# both are also the launcher's defaults (dm/launcher.json from dm/games/settings.py; the player's choice there wins over them, Documents/env.txt over the choice);
|
||||
@@ -123,6 +124,8 @@ if [ "$PREPARE_XCODE" = YES ] && [ -n "${DM_ENTITLEMENTS-default}" ]; then
|
||||
t "entitlements: $(plutil -convert json -o - Gen/DmIOS.entitlements)"
|
||||
fi
|
||||
xcodegen generate -q > /dev/null || die "xcodegen"
|
||||
# DM_METAL_CAPTURE=1: a development build that may write GPU frame captures (MetalCaptureEnabled; the host's DM_GPU_CAPTURE switch writes them to Documents/gpu_captures)
|
||||
if [ "${DM_METAL_CAPTURE:-0}" = 1 ]; then /usr/libexec/PlistBuddy -c "Add :MetalCaptureEnabled bool true" Gen/Info.plist > /dev/null || die "MetalCaptureEnabled"; t "Metal frame capture: enabled (DM_METAL_CAPTURE=1)"; fi
|
||||
python3 tools/gen_resources.py "$IOS" "$ROMFS" "$MARKER" "$MSL_IOS/$MSLDIR" "$MSLDIR" "$AOC" "$XCODE_DD" "$DM/gfx/nvn/dmsh_chain.h" "$PSO" || die "generate Xcode resource paths"
|
||||
if [ "$PREPARE_XCODE" = YES ]; then
|
||||
t "Xcode project: $IOS/DmIOS.xcodeproj"
|
||||
|
||||
Executable
+216
@@ -0,0 +1,216 @@
|
||||
#!/usr/bin/env python3
|
||||
"""Summarise the host's GPU profile lines in a log (Mac run log or the iPhone's Documents/log.txt).
|
||||
|
||||
DM_NVN_GPUPROF=<frame>[-<frame>] or every:<n> prints one "[gpuprof]" line per encoder of the profiled frames (render pass: size, colour attachments, depth, draws,
|
||||
attachment load / store KB, Metal pixel formats; compute / copy: copies, uniform updates, dispatches) and a "frame" line per frame. DM_AB=<frames> prints one "[ab]"
|
||||
line per phase. This tool reads both:
|
||||
|
||||
gpuprof.py log.txt per-frame totals, then the mean per frame of each pass shape (size, colours, depth, formats), by GPU time
|
||||
gpuprof.py log.txt --by class the same by size class relative to the frame's largest colour pass (full, half, quarter ... per axis: the same for every game)
|
||||
gpuprof.py log.txt --frames 600 1200 only those frames
|
||||
gpuprof.py log.txt --timeline 600 every encoder of frame 600 in GPU order, with the idle gaps between them
|
||||
gpuprof.py log.txt --ab the [ab] phases: medians per configuration and the difference from the base
|
||||
|
||||
Times are GPU timestamps taken where each encoder begins and ends (relaxed: encoders may overlap), so the sum over encoders is not the frame's GPU time; the frame line's
|
||||
span (first start to last end) is closer to it. See docs/agents/05-debugging.md, "GPU time on the device".
|
||||
"""
|
||||
import argparse, collections, re, statistics, sys
|
||||
|
||||
ENC = re.compile(r'\[gpuprof\] F(\d+)\s+(\d+)\s+([\d.]+) us (render pass|compute / copy)(.*)')
|
||||
RP = re.compile(r'^ (\d+) (\d+)x(\d+) colors (\d+) depth (\d+) loads (\d+) draws (\d+) start ([+-][\d.]+) seg (\d+)(?: load (\d+) KB store (\d+) KB)?(?: fmt (\d+)/(\d+))?')
|
||||
CP = re.compile(r'^ after pass (\d+) start ([+-][\d.]+) seg (\d+) copies (\d+) \(uniform updates (\d+)\) dispatches (\d+)')
|
||||
FRAME = re.compile(r'\[gpuprof\] frame (\d+): render ([\d.]+) ms, compute / copy ([\d.]+) ms over (\d+) encoders.*?first start to last end ([\d.]+) ms')
|
||||
AB = re.compile(r'\[ab\] phase (\d+) (\S+): (\d+) frames, GPU p50 ([\d.]+) / p90 ([\d.]+) / mean ([\d.]+) ms, frame p50 ([\d.]+) / p90 ([\d.]+) / mean ([\d.]+) ms'
|
||||
r'(?:; per frame: attachments load ([\d.]+) MB store ([\d.]+) MB, passes ([\d.]+))?')
|
||||
|
||||
# MTLPixelFormat values the profile prints (fmt <colour 0>/<depth or stencil>; 0 = none)
|
||||
MTL_FORMATS = {
|
||||
1: 'A8Unorm', 10: 'R8Unorm', 11: 'R8Unorm_sRGB', 12: 'R8Snorm', 13: 'R8Uint', 14: 'R8Sint', 20: 'R16Unorm', 22: 'R16Snorm', 23: 'R16Uint', 24: 'R16Sint',
|
||||
25: 'R16Float', 30: 'RG8Unorm', 31: 'RG8Unorm_sRGB', 32: 'RG8Snorm', 33: 'RG8Uint', 34: 'RG8Sint', 40: 'B5G6R5Unorm', 41: 'A1BGR5Unorm', 42: 'ABGR4Unorm',
|
||||
43: 'BGR5A1Unorm', 53: 'R32Uint', 54: 'R32Sint', 55: 'R32Float', 60: 'RG16Unorm', 62: 'RG16Snorm', 63: 'RG16Uint', 64: 'RG16Sint', 65: 'RG16Float',
|
||||
70: 'RGBA8Unorm', 71: 'RGBA8Unorm_sRGB', 72: 'RGBA8Snorm', 73: 'RGBA8Uint', 74: 'RGBA8Sint', 80: 'BGRA8Unorm', 81: 'BGRA8Unorm_sRGB', 90: 'RGB10A2Unorm',
|
||||
91: 'RGB10A2Uint', 92: 'RG11B10Float', 93: 'RGB9E5Float', 94: 'BGR10A2Unorm', 103: 'RG32Uint', 104: 'RG32Sint', 105: 'RG32Float', 110: 'RGBA16Unorm',
|
||||
112: 'RGBA16Snorm', 113: 'RGBA16Uint', 114: 'RGBA16Sint', 115: 'RGBA16Float', 123: 'RGBA32Uint', 124: 'RGBA32Sint', 125: 'RGBA32Float',
|
||||
250: 'Depth16Unorm', 252: 'Depth32Float', 253: 'Stencil8', 255: 'Depth24Unorm_Stencil8', 260: 'Depth32Float_Stencil8', 261: 'X32_Stencil8', 262: 'X24_Stencil8',
|
||||
}
|
||||
|
||||
|
||||
def fmt_name(v):
|
||||
return MTL_FORMATS.get(v, str(v)) if v else '-'
|
||||
|
||||
|
||||
Enc = collections.namedtuple('Enc', 'frame idx us kind pass_ w h colors depth loads draws start seg load_kb store_kb cfmt dfmt copies ubd dispatches')
|
||||
|
||||
|
||||
def parse(lines):
|
||||
"""[gpuprof] encoder lines by frame (in log order) and the frame lines ({frame: dict}); lines that do not match are skipped"""
|
||||
frames, flines = collections.OrderedDict(), {}
|
||||
for line in lines:
|
||||
if '[gpuprof]' not in line: continue
|
||||
m = ENC.search(line)
|
||||
if m:
|
||||
f, idx, us, kind, rest = int(m.group(1)), int(m.group(2)), float(m.group(3)), m.group(4), m.group(5)
|
||||
if kind == 'render pass':
|
||||
r = RP.match(rest)
|
||||
if not r: continue
|
||||
g = [int(x) if x is not None else 0 for x in (r.group(1), r.group(2), r.group(3), r.group(4), r.group(5), r.group(6), r.group(7))]
|
||||
e = Enc(f, idx, us, 'R', g[0], g[1], g[2], g[3], g[4], g[5], g[6], float(r.group(8)), int(r.group(9)),
|
||||
int(r.group(10) or 0), int(r.group(11) or 0), int(r.group(12) or 0), int(r.group(13) or 0), 0, 0, 0)
|
||||
else:
|
||||
c = CP.match(rest)
|
||||
if not c: continue
|
||||
e = Enc(f, idx, us, 'C', int(c.group(1)), 0, 0, 0, 0, 0, 0, float(c.group(2)), int(c.group(3)), 0, 0, 0, 0,
|
||||
int(c.group(4)), int(c.group(5)), int(c.group(6)))
|
||||
frames.setdefault(f, []).append(e)
|
||||
continue
|
||||
m = FRAME.search(line)
|
||||
if m:
|
||||
flines[int(m.group(1))] = {'render_ms': float(m.group(2)), 'compute_ms': float(m.group(3)), 'encoders': int(m.group(4)), 'span_ms': float(m.group(5))}
|
||||
return frames, flines
|
||||
|
||||
|
||||
def frame_stats(es):
|
||||
"""Totals of one frame's encoders: sum of their times, span from the first start to the last end, idle time between them (GPU order)"""
|
||||
es = sorted(es, key=lambda e: e.start)
|
||||
tot = sum(e.us for e in es)
|
||||
span = max(e.start + e.us for e in es) - es[0].start
|
||||
gaps, end = 0.0, es[0].start
|
||||
for e in es:
|
||||
if e.start > end: gaps += e.start - end
|
||||
end = max(end, e.start + e.us)
|
||||
rp = [e for e in es if e.kind == 'R']
|
||||
return {'encoders': len(es), 'passes': len(rp), 'sum_us': tot, 'span_us': span, 'gap_us': gaps, 'draws': sum(e.draws for e in rp),
|
||||
'load_kb': sum(e.load_kb for e in rp), 'store_kb': sum(e.store_kb for e in rp)}
|
||||
|
||||
|
||||
def shape_key(e):
|
||||
if e.kind != 'R': return 'compute / copy'
|
||||
z = '+d' if e.depth else ''
|
||||
f = fmt_name(e.cfmt) if e.colors else ''
|
||||
d = fmt_name(e.dfmt) if e.dfmt else ''
|
||||
return f'{e.w}x{e.h} {e.colors}c{z} {f}{"/" if f and d else ""}{d}'.rstrip()
|
||||
|
||||
|
||||
def class_key(e, ref_area):
|
||||
"""A size class relative to the frame's largest colour pass (ref_area pixels), by the scale per axis: the same classes for every game and resolution.
|
||||
Passes with four colour attachments or more are their own class (a deferred renderer's G-buffer); <=2 draws marks full-screen work (post-processing, copies)"""
|
||||
if e.kind != 'R': return 'compute / copy'
|
||||
area = e.w * e.h
|
||||
if e.colors == 0: return 'depth only (shadow maps)' if e.depth else 'no attachments'
|
||||
if area <= 64 * 64: return 'tiny (<=64x64)'
|
||||
s = (area / ref_area) ** 0.5 if ref_area else 1 # the scale per axis: 800x450 is half of 1600x900
|
||||
size = 'full' if s >= 0.7 else 'half' if s >= 0.35 else 'quarter' if s >= 0.18 else 'eighth' if s >= 0.09 else 'small'
|
||||
if e.colors >= 4: return f'{size}, {e.colors} colours{" + depth" if e.depth else ""}'
|
||||
return f'{size}, {"<=2 draws" if e.draws <= 2 else ">2 draws"}{" + depth" if e.depth else ""}'
|
||||
|
||||
|
||||
def aggregate(frames, by='shape', only=None):
|
||||
"""Mean per frame of each group over the frames: (rows sorted by GPU time, number of frames). A row: group, passes, us, draws, load KB, store KB"""
|
||||
agg = collections.defaultdict(lambda: [0, 0.0, 0, 0, 0]); nf = 0
|
||||
for f, es in frames.items():
|
||||
if only and f not in only: continue
|
||||
nf += 1
|
||||
ref = max((e.w * e.h for e in es if e.kind == 'R' and e.colors), default=0)
|
||||
for e in es:
|
||||
k = shape_key(e) if by == 'shape' else class_key(e, ref)
|
||||
a = agg[k]; a[0] += 1; a[1] += e.us; a[2] += e.draws; a[3] += e.load_kb; a[4] += e.store_kb
|
||||
rows = [(k, v[0] / nf, v[1] / nf, v[2] / nf, v[3] / nf, v[4] / nf) for k, v in agg.items()] if nf else []
|
||||
rows.sort(key=lambda r: -r[2])
|
||||
return rows, nf
|
||||
|
||||
|
||||
def parse_ab(lines):
|
||||
out = []
|
||||
for line in lines:
|
||||
m = AB.search(line)
|
||||
if not m: continue
|
||||
g = m.groups()
|
||||
out.append({'phase': int(g[0]), 'config': g[1], 'frames': int(g[2]), 'gpu_p50': float(g[3]), 'gpu_p90': float(g[4]), 'gpu_mean': float(g[5]),
|
||||
'frame_p50': float(g[6]), 'frame_p90': float(g[7]), 'frame_mean': float(g[8]),
|
||||
'load_mb': float(g[9]) if g[9] else None, 'store_mb': float(g[10]) if g[10] else None, 'passes': float(g[11]) if g[11] else None})
|
||||
return out
|
||||
|
||||
|
||||
def ab_summary(phases, skip=1):
|
||||
"""Median of each value over the phases of each configuration, leaving out the first <skip> phases (loading, first-use pipeline builds)"""
|
||||
by = collections.OrderedDict()
|
||||
for p in phases:
|
||||
if p['phase'] < skip: continue
|
||||
by.setdefault(p['config'], []).append(p)
|
||||
res = collections.OrderedDict()
|
||||
for cfg, ps in by.items():
|
||||
r = {'phases': len(ps)}
|
||||
for k in ('gpu_p50', 'gpu_p90', 'gpu_mean', 'frame_p50', 'frame_p90', 'frame_mean', 'load_mb', 'store_mb', 'passes'):
|
||||
v = [p[k] for p in ps if p[k] is not None]
|
||||
r[k] = statistics.median(v) if v else None
|
||||
res[cfg] = r
|
||||
return res
|
||||
|
||||
|
||||
def main(argv=None):
|
||||
ap = argparse.ArgumentParser(description=__doc__.split('\n\n')[0])
|
||||
ap.add_argument('log', help='the run log or Documents/log.txt')
|
||||
ap.add_argument('--frames', type=int, nargs='+', help='only these profiled frames')
|
||||
ap.add_argument('--by', choices=('shape', 'class'), default='shape', help='group passes by exact shape (default) or by size class relative to the largest colour pass')
|
||||
ap.add_argument('--top', type=int, default=25, help='groups listed (default 25); the rest are summed as "other"')
|
||||
ap.add_argument('--timeline', type=int, metavar='FRAME', help='every encoder of that frame in GPU order')
|
||||
ap.add_argument('--ab', action='store_true', help='summarise the DM_AB [ab] lines instead')
|
||||
ap.add_argument('--ab-skip', type=int, default=1, help='with --ab: phases left out at the start (default 1)')
|
||||
a = ap.parse_args(argv)
|
||||
with open(a.log, errors='replace') as fh: lines = fh.readlines()
|
||||
|
||||
if a.ab:
|
||||
phases = parse_ab(lines)
|
||||
if not phases: print('no [ab] lines (DM_AB=<frames> with a switch set to ab)', file=sys.stderr); return 1
|
||||
res = ab_summary(phases, a.ab_skip)
|
||||
print(f'{len(phases)} phases; medians per configuration (first {a.ab_skip} left out):')
|
||||
print(f' {"configuration":32s} {"phases":>6s} {"GPU p50":>8s} {"GPU p90":>8s} {"frame p50":>9s} {"frame p90":>9s} {"load MB":>8s} {"store MB":>8s} {"passes":>7s}')
|
||||
f1 = lambda v, w=8: f'{v:{w}.2f}' if v is not None else ' ' * (w - 1) + '-'
|
||||
for cfg, r in res.items():
|
||||
print(f' {cfg:32s} {r["phases"]:6d} {f1(r["gpu_p50"])} {f1(r["gpu_p90"])} {f1(r["frame_p50"], 9)} {f1(r["frame_p90"], 9)} {f1(r["load_mb"])} {f1(r["store_mb"])} {f1(r["passes"], 7)}')
|
||||
base = res.get('base')
|
||||
if base:
|
||||
for cfg, r in res.items():
|
||||
if cfg == 'base': continue
|
||||
print(f' {cfg} - base: GPU p50 {r["gpu_p50"] - base["gpu_p50"]:+.2f} ms, frame p50 {r["frame_p50"] - base["frame_p50"]:+.2f} ms')
|
||||
return 0
|
||||
|
||||
frames, flines = parse(lines)
|
||||
if not frames: print('no [gpuprof] encoder lines (DM_NVN_GPUPROF=<frame> or every:<n>)', file=sys.stderr); return 1
|
||||
only = set(a.frames) if a.frames else None
|
||||
|
||||
if a.timeline is not None:
|
||||
es = frames.get(a.timeline)
|
||||
if not es: print(f'frame {a.timeline} was not profiled; profiled: {" ".join(map(str, list(frames)[:20]))}', file=sys.stderr); return 1
|
||||
es = sorted(es, key=lambda e: e.start); end = es[0].start
|
||||
print(f'frame {a.timeline}: {len(es)} encoders in GPU order (start and duration in us; gap = idle before it)')
|
||||
for e in es:
|
||||
gap = max(0.0, e.start - end); end = max(end, e.start + e.us)
|
||||
if e.kind == 'R':
|
||||
what = (f'pass {e.pass_} {e.w}x{e.h} {e.colors}c{"+d" if e.depth else ""} draws {e.draws} loads {e.loads} '
|
||||
f'load {e.load_kb} KB store {e.store_kb} KB {fmt_name(e.cfmt)}/{fmt_name(e.dfmt)}')
|
||||
else:
|
||||
what = f'compute / copy after pass {e.pass_}: copies {e.copies} (uniform updates {e.ubd}) dispatches {e.dispatches}'
|
||||
print(f' {e.idx:4d} +{e.start:9.1f} {e.us:8.1f}{" gap %.1f" % gap if gap >= 1 else "":>12s} {what}')
|
||||
return 0
|
||||
|
||||
for f, es in frames.items():
|
||||
if only and f not in only: continue
|
||||
s = frame_stats(es); fl = flines.get(f)
|
||||
print(f'frame {f}: {s["encoders"]} encoders ({s["passes"]} render passes), sum {s["sum_us"] / 1e3:.2f} ms, span {s["span_us"] / 1e3:.2f} ms, idle {s["gap_us"] / 1e3:.2f} ms, '
|
||||
f'draws {s["draws"]}, attachments load {s["load_kb"] / 1024:.0f} MB store {s["store_kb"] / 1024:.0f} MB'
|
||||
+ (f' | host: render {fl["render_ms"]:.2f} ms, compute / copy {fl["compute_ms"]:.2f} ms' if fl else ''))
|
||||
rows, nf = aggregate(frames, a.by, only)
|
||||
tot = sum(r[2] for r in rows) or 1
|
||||
print(f'\nmean per frame over {nf} frames, by {a.by}:')
|
||||
print(f' {"group":52s} {"passes":>7s} {"ms":>7s} {"share":>6s} {"us/pass":>8s} {"draws":>7s} {"load MB":>8s} {"store MB":>8s}')
|
||||
shown, rest = rows[:a.top], rows[a.top:]
|
||||
if rest: shown = shown + [('other (%d groups)' % len(rest), sum(r[1] for r in rest), sum(r[2] for r in rest), sum(r[3] for r in rest), sum(r[4] for r in rest), sum(r[5] for r in rest))]
|
||||
for k, n, us, dr, ld, st in shown:
|
||||
print(f' {k:52s} {n:7.1f} {us / 1e3:7.2f} {100 * us / tot:5.1f}% {us / n if n else 0:8.1f} {dr:7.0f} {ld / 1024:8.1f} {st / 1024:8.1f}')
|
||||
print(f' {"total":52s} {sum(r[1] for r in rows):7.1f} {tot / 1e3:7.2f}')
|
||||
return 0
|
||||
|
||||
|
||||
if __name__ == '__main__':
|
||||
sys.exit(main())
|
||||
@@ -0,0 +1,105 @@
|
||||
#!/usr/bin/env python3
|
||||
# dm/tools/gpuprof.py: the host's [gpuprof] and [ab] lines (DM_NVN_GPUPROF, DM_AB) parsed from a synthetic log, the per-frame totals, the groupings and the A/B medians
|
||||
import contextlib, importlib.util, io, os, sys, tempfile, unittest
|
||||
from pathlib import Path
|
||||
|
||||
REPO = Path(__file__).resolve().parents[3]
|
||||
spec = importlib.util.spec_from_file_location('gpuprof', REPO / 'dm/tools/gpuprof.py'); gpuprof = importlib.util.module_from_spec(spec); spec.loader.exec_module(gpuprof)
|
||||
|
||||
P = '[dm] [nvn-mtl] [gpuprof] '
|
||||
|
||||
|
||||
def rp(f, i, us, pas, w, h, nc, d, draws, start, ld, st, cf, df, seg=0):
|
||||
return f'{P}F{f} {i:4d} {us:8.1f} us render pass {pas} {w}x{h} colors {nc} depth {d} loads {1 if ld else 0} draws {draws} start +{start:.1f} seg {seg} load {ld} KB store {st} KB fmt {cf}/{df}'
|
||||
|
||||
|
||||
LOG = [
|
||||
'boot: env DM_NVN_GPUPROF=every:600 (Documents/env.txt)',
|
||||
# frame 600: a G-buffer (4 colours + depth), a full-size lighting pass, a shadow map, a tiny pass and a copy; 20 us idle before the lighting pass
|
||||
rp(600, 0, 400.0, 10, 1600, 900, 4, 1, 300, 0.0, 0, 28125, 70, 260),
|
||||
rp(600, 1, 100.0, 11, 1600, 900, 1, 0, 1, 420.0, 5625, 5625, 115, 0),
|
||||
rp(600, 2, 200.0, 12, 2048, 2048, 0, 1, 500, 520.0, 0, 16384, 0, 252),
|
||||
rp(600, 3, 10.0, 13, 32, 32, 1, 0, 1, 720.0, 4, 4, 70, 0),
|
||||
f'{P}F600 4 30.0 us compute / copy after pass 13 start +730.0 seg 1 copies 3 (uniform updates 2) dispatches 1',
|
||||
f'{P}frame 600: render 0.71 ms, compute / copy 0.03 ms over 5 encoders (4 render passes, attachments load 5.5 MB store 49.0 MB), first start to last end 0.76 ms; clock proxy: x',
|
||||
'an unrelated line [gpuprof] that matches nothing',
|
||||
# frame 1200: the same with a slower G-buffer and no copy
|
||||
rp(1200, 0, 600.0, 20, 1600, 900, 4, 1, 320, 0.0, 0, 28125, 70, 260),
|
||||
rp(1200, 1, 100.0, 21, 1600, 900, 1, 0, 1, 600.0, 5625, 5625, 115, 0),
|
||||
rp(1200, 2, 200.0, 22, 2048, 2048, 0, 1, 500, 700.0, 0, 16384, 0, 252),
|
||||
rp(1200, 3, 10.0, 23, 32, 32, 1, 0, 1, 900.0, 4, 4, 70, 0),
|
||||
f'{P}frame 1200: render 0.91 ms, compute / copy 0.00 ms over 4 encoders (4 render passes, attachments load 5.5 MB store 49.0 MB), first start to last end 0.91 ms',
|
||||
# an older host's line without the ledger and formats still parses
|
||||
f'{P}F1800 0 50.0 us render pass 30 800x450 colors 1 depth 0 loads 0 draws 2 start +0.0 seg 0',
|
||||
'[dm] [nvn-mtl] [ab] phase 0 base: 90 frames, GPU p50 9.00 / p90 10.00 / mean 9.10 ms, frame p50 16.60 / p90 17.00 / mean 16.70 ms; per frame: attachments load 300 MB store 400 MB, passes 150.0',
|
||||
'[dm] [nvn-mtl] [ab] phase 1 BARRIER: 90 frames, GPU p50 8.00 / p90 9.00 / mean 8.10 ms, frame p50 16.60 / p90 16.90 / mean 16.65 ms; per frame: attachments load 300 MB store 400 MB, passes 150.0',
|
||||
'[dm] [nvn-mtl] [ab] phase 2 base: 90 frames, GPU p50 7.00 / p90 8.00 / mean 7.10 ms, frame p50 16.70 / p90 17.10 / mean 16.80 ms; per frame: attachments load 300 MB store 400 MB, passes 150.0',
|
||||
'[dm] [nvn-mtl] [ab] phase 3 BARRIER: 90 frames, GPU p50 6.50 / p90 7.50 / mean 6.60 ms, frame p50 16.60 / p90 16.80 / mean 16.62 ms; per frame: attachments load 300 MB store 400 MB, passes 150.0',
|
||||
'[dm] [nvn-mtl] [ab] phase 4 base: 90 frames, GPU p50 7.20 / p90 8.10 / mean 7.30 ms, frame p50 16.70 / p90 17.00 / mean 16.75 ms; per frame: attachments load 300 MB store 400 MB, passes 150.0',
|
||||
]
|
||||
|
||||
|
||||
class GpuProf(unittest.TestCase):
|
||||
def setUp(self):
|
||||
self.frames, self.flines = gpuprof.parse(LOG)
|
||||
|
||||
def test_parse(self):
|
||||
self.assertEqual(list(self.frames), [600, 1200, 1800])
|
||||
self.assertEqual(len(self.frames[600]), 5); self.assertEqual(len(self.frames[1200]), 4)
|
||||
g = self.frames[600][0]
|
||||
self.assertEqual((g.kind, g.w, g.h, g.colors, g.depth, g.draws, g.store_kb, g.cfmt, g.dfmt), ('R', 1600, 900, 4, 1, 300, 28125, 70, 260))
|
||||
c = self.frames[600][4]
|
||||
self.assertEqual((c.kind, c.pass_, c.copies, c.ubd, c.dispatches, c.seg), ('C', 13, 3, 2, 1, 1))
|
||||
old = self.frames[1800][0]
|
||||
self.assertEqual((old.load_kb, old.store_kb, old.cfmt), (0, 0, 0))
|
||||
self.assertEqual(self.flines[600], {'render_ms': 0.71, 'compute_ms': 0.03, 'encoders': 5, 'span_ms': 0.76})
|
||||
self.assertEqual(self.flines[1200]['span_ms'], 0.91)
|
||||
|
||||
def test_frame_stats(self):
|
||||
s = gpuprof.frame_stats(self.frames[600])
|
||||
self.assertEqual((s['encoders'], s['passes'], s['draws']), (5, 4, 802))
|
||||
self.assertAlmostEqual(s['sum_us'], 740.0); self.assertAlmostEqual(s['span_us'], 760.0)
|
||||
self.assertAlmostEqual(s['gap_us'], 20.0) # 400 → 420
|
||||
self.assertEqual((s['load_kb'], s['store_kb']), (5629, 50138))
|
||||
|
||||
def test_shapes(self):
|
||||
rows, nf = gpuprof.aggregate(self.frames, 'shape', {600, 1200})
|
||||
self.assertEqual(nf, 2)
|
||||
top = rows[0]
|
||||
self.assertEqual(top[0], '1600x900 4c+d RGBA8Unorm/Depth32Float_Stencil8')
|
||||
self.assertAlmostEqual(top[1], 1.0); self.assertAlmostEqual(top[2], 500.0); self.assertAlmostEqual(top[3], 310.0)
|
||||
names = [r[0] for r in rows]
|
||||
self.assertIn('2048x2048 0c+d Depth32Float', names); self.assertIn('1600x900 1c RGBA16Float', names); self.assertIn('compute / copy', names)
|
||||
cp = rows[names.index('compute / copy')]; self.assertAlmostEqual(cp[1], 0.5); self.assertAlmostEqual(cp[2], 15.0)
|
||||
|
||||
def test_classes(self):
|
||||
rows, nf = gpuprof.aggregate(self.frames, 'class', {600})
|
||||
d = {r[0]: r for r in rows}
|
||||
self.assertEqual(set(d), {'full, 4 colours + depth', 'full, <=2 draws', 'depth only (shadow maps)', 'tiny (<=64x64)', 'compute / copy'})
|
||||
self.assertAlmostEqual(d['full, 4 colours + depth'][2], 400.0)
|
||||
# the reference is the largest colour pass, not the 2048x2048 shadow map: an 800x450 pass is half of 1600x900 per axis
|
||||
e = self.frames[1800][0]._replace(colors=1, draws=5)
|
||||
self.assertEqual(gpuprof.class_key(e, 1600 * 900), 'half, >2 draws'); self.assertEqual(gpuprof.class_key(e, 3200 * 1800), 'quarter, >2 draws')
|
||||
|
||||
def test_ab(self):
|
||||
phases = gpuprof.parse_ab(LOG)
|
||||
self.assertEqual([p['config'] for p in phases], ['base', 'BARRIER', 'base', 'BARRIER', 'base'])
|
||||
r = gpuprof.ab_summary(phases, skip=1)
|
||||
self.assertEqual(list(r), ['BARRIER', 'base'])
|
||||
self.assertEqual(r['base']['phases'], 2); self.assertAlmostEqual(r['base']['gpu_p50'], 7.1); self.assertAlmostEqual(r['BARRIER']['gpu_p50'], 7.25)
|
||||
self.assertEqual(r['base']['passes'], 150.0)
|
||||
|
||||
def test_cli(self):
|
||||
with tempfile.TemporaryDirectory() as d:
|
||||
p = Path(d) / 'log.txt'; p.write_text('\n'.join(LOG) + '\n')
|
||||
for args, want in ((['--by', 'class'], 'full, 4 colours + depth'), (['--timeline', '600'], 'gap 20.0'), (['--ab'], 'BARRIER - base: GPU p50 +0.15 ms'),
|
||||
(['--frames', '600', '--top', '2'], 'other (3 groups)')):
|
||||
out = io.StringIO()
|
||||
with contextlib.redirect_stdout(out): rc = gpuprof.main([str(p)] + args)
|
||||
self.assertEqual(rc, 0, args); self.assertIn(want, out.getvalue(), args)
|
||||
err = io.StringIO()
|
||||
with contextlib.redirect_stderr(err): self.assertEqual(gpuprof.main([str(p), '--timeline', '7']), 1)
|
||||
|
||||
|
||||
if __name__ == '__main__':
|
||||
unittest.main()
|
||||
@@ -63,7 +63,7 @@ What earlier titles needed beyond sections 1–5 is filed by mechanism: textures
|
||||
| Switch | Output |
|
||||
|---|---|
|
||||
| `DM_NVN_SHOT=f1,f2:path_%d.png` | Window screenshots at those presented frames |
|
||||
| `DM_NVN_PASSDUMP=f` or `f1-f2` (+ `DM_NVN_PASSDUMP_ALL=1`) | Every render pass of those frames: `P` attachments (with `mtl=` the Metal texture behind them), `C` clear colours, `K` shader keys, `B` each binding's actual source (also with `mtl=`), `d`/`D` draw state (`b0`–`b3` the blend states of targets 0–3; on `d`, `po=` the polygon offset enables / factor, units, clamp and `dc=` depth clamp), `Y` inline updates, `X` texture clears, `T` texture copies, `Z` the game's barriers (their bits, and whether one ended the pass), `N` passes skipped because no attachment could be attached, `C` buffer-to-texture copies (target, size, format, region, source address, row and image strides), `W` image bindings of compute dispatches; a buffer texture's `B` line gives its format, element count and storage address (for the Mac's `DM_CTL` `memdump`). Without `_ALL` the `K` / `B` / `R` lines cover only the first draw of each pass |
|
||||
| `DM_NVN_PASSDUMP=f`, `f1-f2` or `every:n` (+ `DM_NVN_PASSDUMP_ALL=1`) | Every render pass of those frames (`every:n`: one frame in every n, halfway between two `DM_NVN_GPUPROF=every:n` frames): `P` attachments (with `mtl=` the Metal texture behind them), `C` clear colours, `K` shader keys, `B` each binding's actual source (also with `mtl=`), `d`/`D` draw state (`b0`–`b3` the blend states of targets 0–3; on `d`, `po=` the polygon offset enables / factor, units, clamp and `dc=` depth clamp), `Y` inline updates, `X` texture clears, `T` texture copies, `Z` the game's barriers (their bits, and whether one ended the pass), `N` passes skipped because no attachment could be attached, `C` buffer-to-texture copies (target, size, format, region, source address, row and image strides), `W` image bindings of compute dispatches; a buffer texture's `B` line gives its format, element count and storage address (for the Mac's `DM_CTL` `memdump`). Without `_ALL` the `K` / `B` / `R` lines cover only the first draw of each pass |
|
||||
| `DM_NVN_TEXDUMP=f:path_%d.png` (+ `DM_NVN_TEXSNAP=i,…`) | Every colour render target of frame f, as PNG (`%d` = serial × 100 + layer × 10 + level; 2D arrays by the attached layer). `TEXSNAP` copies the attachments of in-frame pass i (2D, or slice 0 of a 2D array) in a separate command buffer, which does not run at the pass's position in the GPU timeline: a snapshot taken right after a clearing pass showed a complete image, so read it as "what this target holds around the frame", not "right after pass i" |
|
||||
| `DM_NVN_TEXDUMP=size=WxH:path_%d.png` | The same dump for the first frame that opens a render pass whose first colour attachment level is W×H: for one-off work (a mask built when a prompt appears) whose frame differs between runs. With `DM_NVN_SNAPRAW=1` each image also gets a `.raw` file with the alpha channel |
|
||||
| `DM_NVN_CBDUMP=dir` (with PASSDUMP) | Raw uniform buffer contents per binding, and the source bytes of every buffer-to-texture copy into a 3D texture (`F<frame>_c3d_<serial>.bin`: what the game uploaded, before any layout question) |
|
||||
@@ -89,11 +89,13 @@ What earlier titles needed beyond sections 1–5 is filed by mechanism: textures
|
||||
| `DM_NVN_UBP_CHECK=1` | Check every uniform shadow read from memory: the pass ends, the updates land, the replay waits for the GPU and compares (`uniform shadow check: N equal, M different`; a difference is a red line). Breath of the Wild outdoors: 388,000 equal, 0 different |
|
||||
| `DM_NVN_LAZY_CLEAR=0` | Clears with no draw after them open a pass of their own when the game sets other targets, as before. By default they wait: the next pass that attaches the same texture level and layer through the same view clears it as its load action, and the rest land in passes of their own before anything else could see their textures (a draw sampling one, a pass not attaching it, any operation other than targets, clears, state, uniform updates and buffer copies or fills, the end of the command list). Off in TBDR mode. The `residency set` line counts clears taken by a later pass and those landed alone |
|
||||
| `DM_NVN_FLUSH_FILL=0` | A new GPU texture in a pool the CPU can write starts as zeros, as before. By default one whose storage the game flushed (`nvnMemoryPoolFlushMappedRange`) before its first use is filled from that storage once (`initial content: … flushed by the CPU before its first use` lines; Breath of the Wild's sky tables) |
|
||||
| `DM_NVN_BARRIER=game` / `full` | How draw passes are ordered. `full` (default): every pass waits for all earlier GPU work. `game`: a pass waits only for the previous pass's fragment stage, so its vertex work overlaps the previous pass's fragments, unless the game called `nvnCommandBufferBarrier` in between or a compute / copy / upload ran (those keep full barriers). Only vertex-stage reads of the previous pass's output without a game barrier change order |
|
||||
| `DM_NVN_BARRIER=game` / `full` / `ab` | How draw passes are ordered (`ab`: alternating with the `DM_AB` phases). `full` (default): every pass waits for all earlier GPU work. `game`: a pass waits only for the previous pass's fragment stage, so its vertex work overlaps the previous pass's fragments, unless the game called `nvnCommandBufferBarrier` in between or a compute / copy / upload ran (those keep full barriers). Only vertex-stage reads of the previous pass's output without a game barrier change order |
|
||||
| `DM_NVN_GPU_TS=segment` / `submission` | What timestamp reports record, instead of the profile's `gpu_timestamps`: the GPU start / end of the segment holding each report, or one time for the whole submission |
|
||||
| `DM_NVN_DISPATCH_OWN=1` | Every compute dispatch in a compute encoder of its own with full barriers, as before (by default dispatches share the copy encoder, `dispatch_enc`) |
|
||||
| `DM_NVN_VCONV_CPU=1` | Integer vertex inputs fed formats of another class are converted on the CPU, as before (by default the shader's `<key>_bv` library takes them through shadow inputs, `vin_on`) |
|
||||
| `DM_NVN_GPUPROF=f` or `f1-f2` | GPU start and duration of every encoder of those frames, from Metal 4 counter heap timestamps (`[gpuprof]` lines: kind, size, attachments, draws, command-buffer segment; a `frame` line with render and compute / copy time and the span from first start to last end) |
|
||||
| `DM_NVN_GPUPROF=f`, `f1-f2` or `every:n` | GPU start and duration of every encoder of those frames (`every:n`: the frames that are multiples of n, for a phone), from Metal 4 counter heap timestamps (`[gpuprof]` lines: kind, size, attachments, draws, command-buffer segment, attachment load / store KB, Metal pixel formats of colour 0 and depth; a `frame` line with render and compute / copy time, attachment traffic and the span from first start to last end). `dm/tools/gpuprof.py` sums them by pass shape ([05](05-debugging.md#gpu-time-on-the-device)) |
|
||||
| `DM_AB=<frames>` | Switches set to `ab` alternate in phases of that many frames, in one process and scene; an `[ab]` line per phase with GPU and frame time and attachment traffic ([05](05-debugging.md#gpu-time-on-the-device)) |
|
||||
| `DM_GPU_CAPTURE=f[:n]` or `gpu:<ms>[:<after>]` | A Metal GPU trace of those frames for Xcode's Metal debugger, in `gpu_captures/` of the working directory ([05](05-debugging.md#gpu-time-on-the-device)) |
|
||||
| `DM_NVN_ENC_THREAD=1` | Metal encoding on a thread of its own: the submit thread records the encoder calls and a worker replays them (`nvn_rec.h`); on by default on iOS (`DM_NVN_ENC_THREAD=0` turns it off), off on macOS |
|
||||
| `DM_NVN_UB_LAZY=n` | The most deferred inline uniform updates kept across a render pass end (default 160): they land before the next copy, a draw or dispatch that reads their memory other than through uniform bindings the shadows cover (`ubd_conflict`, `ubd_conflict_cs`), a transform feedback draw, or the end of the submission, instead of at every pass end; 0 lands them at every pass end, as before |
|
||||
| `DM_NVN_UB_COPY_THREAD=0` | Uniform shadows of 512 bytes or more are copied on the submit thread, as before (by default a worker copies them) |
|
||||
|
||||
@@ -150,6 +150,15 @@ The phone runs an unsigned IPA the user sideloads; nothing is attached to a debu
|
||||
- **Power**: `power up to frame N` covers the window since the previous one, for the whole process: CPU energy in watts and per frame (`task_energy` from `TASK_POWER_INFO_V2`, CPU only; compare per frame when one build holds the frame rate better), CPU time (100% = one core) and the share on performance cores, wakeups per second, the thermal state (0 nominal … 3 critical; changes are also logged as `front end: thermal state → n`), and the two guest threads that yielded most with how many of those yields the back-off turned into sleeps (`DM_YIELD_BACKOFF`, see [docs/development.md](../development.md)), and its spin wait passes with the last loop head. A thread yielding hundreds of thousands of times per window with few back-off sleeps is a busy spin. A busy thread that never yields and is not in the list may poll in a loop the spin wait rule does not take: sample it and look at its loop. `residency set up to frame N` gives residency-set commits and their time, what was added by source line of `nvn_mtl.m` (count, MB), removals, how many draw passes began with a full barrier or without one (`DM_NVN_BARRIER=game`), and segment commits: a source line adding gigabytes per window is allocation churn. It ends with render-target traffic per frame: attachment bytes loaded and stored, passes that load and store everything, and the stores `DM_NVN_UNWRITTEN_DC` saved (the same counters as the TSV's `@rt_load_mb` / `@rt_store_mb`). `threads up to frame N` gives guest-thread CPU time in ms per second by Switch priority band (≤ 44, the main thread's level and above; 45–59; ≥ 60) and the three busiest threads with their priority; it shows what `DM_QOS_MAP` would move. On the Mac the same lines appear; energy readings vary by tens of percent between identical runs, so compare runs interleaved and over the same scene.
|
||||
- **Screen recordings** from the user are useful for timing and visual symptoms; extract frames with `ffmpeg -ss <t> -i rec.mov -frames:v 1 out.png`.
|
||||
|
||||
## GPU time on the device
|
||||
|
||||
Which passes cost GPU time, on the iPhone or the Mac, without Xcode attached. The switches are off by default; on the phone they go in `Documents/env.txt` and the lines come back in `Documents/log.txt`.
|
||||
|
||||
- **A profile every n frames**: `DM_NVN_GPUPROF=every:600` profiles frames 600, 1200, … each on its own (`DM_NVN_GPUPROF=f` or `f1-f2` suits the Mac, where a scripted route reaches the same scene at the same frame). A profiled frame prints one `[gpuprof] F<frame>` line per encoder: its GPU time and start (µs after the frame's first encoder); for a render pass the size, colour attachments, depth, loads, draws, the command-buffer segment, what it loaded and stored of its attachments (`load` / `store` KB, the bandwidth ledger's view: a DontCare store counts nothing) and `fmt <colour 0>/<depth>` as `MTLPixelFormat` numbers; for a compute / copy encoder its copies, uniform updates and dispatches. Then `[gpuprof] frame N: render … ms, compute / copy … ms over … encoders (… render passes, attachments load … MB store … MB), first start to last end … ms`. The timestamps are relaxed, so encoders overlap: their sum is not the frame's GPU time, the span is closer. It costs two timestamps per encoder; the frame runs as usual. `DM_NVN_PASSDUMP=every:600` adds a pass dump halfway between two profiled frames, for the shader keys of an expensive pass shape.
|
||||
- **Reading them**: `python3 dm/tools/gpuprof.py log.txt` prints per-frame totals (sum, span, idle time between encoders, draws, attachment traffic), then the mean per frame of each pass shape (size, colours, depth, formats), the most expensive first. `--by class` groups by size relative to the frame's largest colour pass instead (full, half, quarter … per axis; passes with four colours or more, a deferred renderer's G-buffer, apart), which compares games and resolutions; `--timeline <frame>` lists one frame's encoders in GPU order with the gaps between them; `--frames` keeps some frames. The GPU clock changes from frame to frame (on the iPhone with its thermal state), so compare means over many profiled frames.
|
||||
- **A/B in one run**: two runs on a phone differ by scene, temperature and clock more than most changes do. `DM_AB=<frames>` alternates every switch set to `ab` in phases of that many frames (on in the odd phases); `ab:<k,…>/<n>` turns it on in the phases whose number modulo n is one of the k, so `ab:1,3/4` on one switch and `ab:2,3/4` on another run four configurations. Each phase prints `[ab] phase N <switches on, or base>` with GPU and whole frame time (p50 / p90 / mean without the phase's first quarter) and attachment traffic and passes per frame; `gpuprof.py log.txt --ab` gives the medians per configuration and their difference from the base. `DM_NVN_BARRIER=ab` is the first such switch; another becomes one by reading its mode with `sw_mode` and asking `sw_on` where it applies (`nvn_mtl.m`).
|
||||
- **A frame for Xcode's Metal debugger** (per-draw cost, the shader profiler): `DM_GPU_CAPTURE=<frame>[:<frames>]`, or `gpu:<ms>[:<after frame>]` for the first frame, after that frame, that follows 60 frames in a row with more than `<ms>` of GPU time, writes `dm_<date>-<time>_f<frame>.gputrace` to `gpu_captures/` in the working directory (`Documents` on iOS, the run folder on the Mac; `DM_GPU_CAPTURE_DIR` names another folder). The iPhone needs an IPA built with `DM_METAL_CAPTURE=1` (`MetalCaptureEnabled` in its `Info.plist`), the Mac `MTL_CAPTURE_ENABLED=1`; on the Mac the `DM_CTL` line `env DM_GPU_CAPTURE=<frame>` sets it while the game runs. A trace takes 1.5–2 GB, so before each capture that folder alone is pruned to the newest `DM_GPU_CAPTURE_KEEP` traces (2, the new one included). Take it off the phone with Finder or the Files app and open it in Xcode. Such a run builds its pipelines through the `MTLDevice` ([GPU frame captures need pipelines built through the device](../reference/shaders.md#gpu-frame-captures-need-pipelines-built-through-the-device)), so time with the profile and look inside with a capture.
|
||||
|
||||
## Offline pipeline link check
|
||||
|
||||
Pipeline link errors depend only on the two libraries, so all vertex / pixel pairs can be checked on the Mac after a shader build, without the game: for each line of `shader_pairs.tsv`, load `<vs>_b.metallib` and `<ps>_b.metallib` from `b-<V>/`, build a vertex descriptor from the vertex function's `vertexAttributes` (format from each attribute's type), set colour attachment formats from the `[[color(n)]]` outputs in the pixel shader's `_b.metal` (uint / int / float formats to match), add a depth format when it writes `[[depth(...)]]`, and call `newRenderPipelineStateWithDescriptor:`. Count failures by message. Mario: 8,712 linked / 331 failed before the vertex output padding, 9,043 / 0 after, and 14,603 / 0 for the v0 + 1.2.1 tables. Pipelines built this way have the default blend state and sample count, so this checks linking only.
|
||||
|
||||
@@ -342,6 +342,7 @@ One line per symptom in the [subsystem references](../reference/): what you see
|
||||
- a scaled texture copy skipped with a red line (Metal blits cannot scale); format-changing, depth-stencil and mirrored copies. → [Copies a blit cannot do, drawn](../reference/rendering.md#copies-a-blit-cannot-do-drawn)
|
||||
- `[RED] Downsample case not implemented: 320x176 1 samples format 70 → 80x48`; a missing bloom. → [`Downsample` of a single-sample texture](../reference/rendering.md#downsample-of-a-single-sample-texture)
|
||||
- no ambient occlusion (Mac); on a device the result depends on whatever that memory holds. → [Depth-stencil copies carry the stencil](../reference/rendering.md#depth-stencil-copies-carry-the-stencil)
|
||||
- `DM_NVN_GPUPROF=every:1` prints no per-frame reports and fills its timestamp heap across frames. → [Periodic GPU profiles close at frame boundaries](../reference/rendering.md#periodic-gpu-profiles-close-at-frame-boundaries)
|
||||
- the 3D scene black (targets cleared again before they are read); `[RED] SetRenderEnableConditional: the host draws anyway`; with a game that skips clears under render conditions, scenes black behind the HUD (Mario vs. Donkey Kong's levels, 1.0.1). → [Conditional rendering evaluated at replay](../reference/rendering.md#conditional-rendering-evaluated-at-replay)
|
||||
- no SPIR-V file in the RomFS; SPIRV-Cross refuses a module with "Struct member does not have ArrayStride set". → [Vulkan shaders generated at run time](../reference/rendering.md#vulkan-shaders-generated-at-run-time)
|
||||
- a crash in `bind_res` reading a freed view's texture (Super Mario Galaxy 2 on an iPhone, element 1 of the 8-texture array, when the ship took off after the first galaxy; GitHub issue 68). → [Descriptors hold the Metal objects they were written with](../reference/rendering.md#descriptors-hold-the-metal-objects-they-were-written-with)
|
||||
@@ -424,6 +425,7 @@ One line per symptom in the [subsystem references](../reference/): what you see
|
||||
- `fragmentFunction main0 cannot be used to build a pipeline state` (a Metal validation assertion). → [Function constants specialized at load](../reference/shaders.md#function-constants-specialized-at-load)
|
||||
- a pipeline for a vertex shader that writes `render_target_array_index` cannot be built. → [Layer-writing vertex shaders get the triangle class](../reference/shaders.md#layer-writing-vertex-shaders-get-the-triangle-class)
|
||||
- the picture bright green and white from some scene on, in runs with pipelines compiled on demand (prewarm lists off or short) and in none with `DM_NVN_PREDICT=0`. → [The precompile look-ahead restores the scissor](../reference/shaders.md#the-precompile-look-ahead-restores-the-scissor)
|
||||
- a GPU frame capture (`DM_GPU_CAPTURE`, or Xcode with `MTL_CAPTURE_ENABLED=1`) fails with `Capturing Render pipeline specialization is not supported`, or the capture layer crashes on the pipeline archive; a capture of the `MTLDevice` is refused. → [GPU frame captures need pipelines built through the device](../reference/shaders.md#gpu-frame-captures-need-pipelines-built-through-the-device)
|
||||
- the first boot sat on the loading clock for about a minute, the CPU idle, with every file read done after 12 s. → [A cold Metal cache looks like a long load](../reference/shaders.md#a-cold-metal-cache-looks-like-a-long-load)
|
||||
|
||||
## Game state
|
||||
|
||||
@@ -182,6 +182,10 @@ Reuse works as for the IPA. Each shader output has its own key, named after the
|
||||
|
||||
Relative output and variant paths are resolved from the terminal's working directory before the host starts in its run folder. Each metric's median and range use the runs that supplied it; a missing optional GPU or game-speed reading leaves a dash when no run supplied one. A failed launch releases `--lock` so another measurement can run.
|
||||
|
||||
### GPU measurement
|
||||
|
||||
The benchmark gives each frame's GPU time; these switches split it by pass, on the Mac or on an iPhone (`Documents/env.txt`), and are off by default: `DM_NVN_GPUPROF=every:<n>` (each encoder's GPU time and attachment traffic in one frame of every n), `DM_NVN_PASSDUMP=every:<n>`, `DM_AB=<frames>` (switches set to `ab` alternate in phases of one run) and `DM_GPU_CAPTURE` (Metal GPU traces for Xcode, written to `DM_GPU_CAPTURE_DIR`, by default `gpu_captures/` in the working directory, which keeps the newest `DM_GPU_CAPTURE_KEEP`; an IPA built with `DM_METAL_CAPTURE=1`, or `MTL_CAPTURE_ENABLED=1` on the Mac). `dm/tools/gpuprof.py` reads their log lines. How to use them: [05, GPU time on the device](agents/05-debugging.md#gpu-time-on-the-device).
|
||||
|
||||
### A Mac app
|
||||
|
||||
`--platform mac-app` (`PLATFORM = 'mac-app'` in Spyder) builds everything `--platform mac` builds, then packs a Mac app of the game with `dm/mac/pack_app.py`. The app is `<NSP folder>/<game name>.app` (a `:` or `/` in the name becomes ` - `); `-o` names another path ending in `.app`. Open it from Finder, from any folder: it does not need the build folder or the drive it is on. Like the Mac host, it needs a Mac with Apple silicon. Its name, version and bundle ID are the IPA's: the game name and display version from the control data, and `org.nxnative.<title ID>`. Its icon is the game's icon as `AppIcon.icns` (`sips`, `iconutil`).
|
||||
@@ -290,6 +294,7 @@ Notes on these steps:
|
||||
- The icon is the `icon.jpg` that `nx_extract` saves next to `RomFS/`; `DM_ICON=` points at another image.
|
||||
- `DM_ENV_FILE=` bakes environment switches into the app, and `DM_DISPLAY_NAME=` renames it.
|
||||
- `DM_LANG=<code>` is the game language (`DMLanguage` in `Info.plist`, default `en-US`; `main.m` sets `DM_LANG` from it unless `Documents/env.txt` or the baked env file sets it).
|
||||
- `DM_METAL_CAPTURE=1` makes a build that can write GPU frame captures (`MetalCaptureEnabled` in `Info.plist`, for `DM_GPU_CAPTURE`, [GPU measurement](#gpu-measurement)).
|
||||
- `DM_SHOW_FPS=1` turns the frame-rate counter on (`DMShowFPS` in `Info.plist`, which `front_ios.m` reads; `DM_SHOW_FPS` in `Documents/env.txt` overrides it). It counts the frames put on screen each second (`mtl_present_count`), so frames the display link merges away are not counted.
|
||||
- The unsigned build pins its build product and intermediate directories inside `$W/build/ios/pkg/dd`, independently of Xcode's Locations preference.
|
||||
- hactool cannot read every update (Mario 1.2.1's patch NCA gives "Invalid BKTR layout!"), which is why `nx_extract` uses LibHac.
|
||||
@@ -416,6 +421,7 @@ Each game's notes are in its profile folder, `dm/games/<id>/README.md`: what the
|
||||
| `nx_extract/` | NSP → ExeFS / RomFS / icon with LibHac, merging an update over the base game (C#, `dotnet build`). `--manifest` writes ExeFS and a RomFS file list only, for surveys |
|
||||
| `nso_fnmap.py` | Carries offsets from one build to another (function matching with addresses masked; globals via their references) |
|
||||
| `nso2elf.py` | Converts NSO to ELF for Ghidra / REA |
|
||||
| `gpuprof.py` | Sums the host's `[gpuprof]` lines (`DM_NVN_GPUPROF`) by pass shape or size class, lists one frame's encoders in GPU order, and gives the medians of the `[ab]` phases (`DM_AB`) |
|
||||
| `insn_census.py` | Counts the instruction sites the rewriter must handle |
|
||||
| `nso_code.py` | Function ranges from `.eh_frame` and the data blocks in a text segment, which the rewriter and the census leave out |
|
||||
| `nso_syms.py` | Compares the SDK import surface of two games, or of one game (`-` for the reference) with the host hooks |
|
||||
|
||||
@@ -567,6 +567,13 @@ The replay on Metal (`dm/gfx/nvn/nvn_mtl.m`) and the Vulkan and OpenGL layers. E
|
||||
- **Fix:** the copy now carries the stencil.
|
||||
- **Found on:** [The Legend of Zelda: Link's Awakening](../../dm/games/01006BB00C6F0000/README.md): the occlusion pass (`aa05724ffa62cb82`, a 480×270 R8 target cleared to 1.0) only writes where stencil bit 1 of the quarter-size depth-stencil copy is clear, so on the Mac the mask kept 1.0 everywhere.
|
||||
|
||||
### Periodic GPU profiles close at frame boundaries
|
||||
|
||||
- **Symptom:** `DM_NVN_GPUPROF=every:1` prints no per-frame reports and fills its timestamp heap across frames.
|
||||
- **Cause:** reporting waited for a submission in an unselected frame. Every frame is selected at interval 1, so that condition never holds.
|
||||
- **Fix:** before the next frame's first encoder, `gp_periodic_finish` snapshots the sampled frame's labels and registers a shared-event notification at its last committed fence. The report resolves the heap after all of that frame's segments complete, without a GPU wait or an extra command buffer. The heap cannot be reused while the report is pending.
|
||||
- **Found on:** review of the measurement tools for [The Legend of Zelda: Breath of the Wild](../../dm/games/01007EF00011E000/README.md); reproduced with synthetic counters and completion events, without game execution. `t_gpuprof` checks consecutive and sparse frame selection, completion ordering and heap ownership; it runs in CPU CI.
|
||||
|
||||
## Conditional rendering and queries
|
||||
|
||||
### Conditional rendering evaluated at replay
|
||||
|
||||
@@ -741,6 +741,13 @@ shader on a GPU.
|
||||
- **Found on:** [OCTOPATH TRAVELER II](../../dm/games/0100A3501946E000/README.md): from Castti's opening flashback and the battlefield of Hikari's opening on.
|
||||
- **Check:** found by bisecting with four runs started at once on copies of one save: `DM_NVN_PREDICT=0` fixed it, a look-ahead that compiled nothing did not, and of its parts only the state ops brought it back; four runs green before the fix, four right after it.
|
||||
|
||||
### GPU frame captures need pipelines built through the device
|
||||
|
||||
- **Symptom:** a GPU frame capture (`DM_GPU_CAPTURE`, or Xcode with `MTL_CAPTURE_ENABLED=1`) fails with `Capturing Render pipeline specialization is not supported`, or the capture layer crashes on the pipeline archive; a capture of the `MTLDevice` is refused.
|
||||
- **Cause:** Metal cannot capture pipelines made from Metal 4 bases (`DM_PSO_MTL4`, the default on the Mac), and its Metal 4 to 3 conversion for the capture layer crashed on the pipeline archive. A device the replay drives through Metal 4 cannot be the capture object.
|
||||
- **Fix:** a run that may capture (`DM_GPU_CAPTURE` or `MTL_CAPTURE_ENABLED` set) builds its render pipelines through the `MTLDevice`, without bases or archive (`pso4_on`), and `gpu_capture_frame` captures the Metal 4 queue (`g_q4`): work on the old queue (present, some uploads) is not in the trace. Such a run builds pipelines more slowly than a normal one, so its frame times are not the game's. Every game.
|
||||
- **Found on:** [The Legend of Zelda: Breath of the Wild](../../dm/games/01007EF00011E000/README.md) (Mac and iPhone).
|
||||
|
||||
### A cold Metal cache looks like a long load
|
||||
|
||||
- **Symptom:** the first boot sat on the loading clock for about a minute, the CPU idle, with every file read done after 12 s.
|
||||
|
||||
Reference in new issue
Block a user