Failure report: task / mesh draws with their grids, +pull marks, and DM_NVN_MESHLOG_CB (with an opt-in GPU copy of the task's uniform words)

dm/games/04003F40232DE000/README.md

@@ -1,6 +1,6 @@
 # Hyrule Warriors: Age of Imprisonment (`04003F40232DE000`)
 
-A Switch 2 game: update v196608, SDK 20.5.15 built for the Switch 2 (`Ounce`). Koei Tecmo's KTGL engine on NVN2, modules `main`, `subsdk0` (NintendoSDK_movie: VP9 movies) and `sdk`. **Plays on the Mac** from a new save through the first-run settings, the opening movies and cutscenes into the first field, where Zelda walks; the frame time's median is 16.6 ms there, with long frames every few frames on a 16 GB Mac ([Performance](#performance)). Battles have not been reached. No IPA has been built.
+A Switch 2 game: update v196608, SDK 20.5.15 built for the Switch 2 (`Ounce`). Koei Tecmo's KTGL engine on NVN2, modules `main`, `subsdk0` (NintendoSDK_movie: VP9 movies) and `sdk`. **Plays on the Mac** from a new save through the first-run settings, the opening movies and cutscenes into the first field, where Zelda walks; the frame time's median is 16.6 ms there, with long frames every few frames on a 16 GB Mac ([Performance](#performance)). The first battle (the village) plays at 1x and at 2x; the first outpost mission froze the GPU once in the Mac app ([GPU hang in a battle](#gpu-hang-in-a-battle-open)). No IPA has been built.
 
 ## What it needs
 
@@ -29,6 +29,15 @@ The rewritten modules take 62.5 MB, so the default `mem_used` (64 MB) covers the
 - Resolved: about 10 fps (p50 100 ms) in the field. Each dedicated c1 constant block of the partial library was a Metal buffer of its own, and the residency set's 16,118 objects made every commit slow ([Dedicated c1 constants as slices of a bank](../../../docs/reference/frame-rate.md#dedicated-c1-constants-as-slices-of-a-bank)).
 - Current (open): the Metal driver wires and unwires memory for each submission, 2.8 s of every 4 s in a Metal System Trace. The game's own GPU memory pool is a constant 4,655 MB (`main+0x19eb098`), with a second pool of 350 MB, and its GPU allocations total 7 GB; the 16 GB Mac had 9.7 GB wired system-wide and about 160 MB free. With fewer commits per frame (`DM_NVN_CUT=0`) p99 was 52–69 ms. A Mac with more memory has not been tried.
 
+## GPU hang in a battle (open)
+
+On 2026-11-04 the Mac app froze in the first outpost mission while a special attack filled the screen, after 18 minutes at a locked 60 fps (host 48b9911e, `DM_UPSCALE=2` scaling nothing yet). The game kept running (its threads poll and wait) while the GPU showed 100 % utilization for minutes and the host's submit thread waited without a timeout for the oldest submission's fence (`mtl_wait_at`, site WS_ALLOC): the picture froze in silence. The evidence is in the work folder's `logs/freeze-20261104-1938/` (host log, a 5 s `sample`, the pipeline ledger) with a README.
+
+- The four pipeline bases compiled at that instant are (`c13c00c6b467d521`, `1bcc1a39c37f54eb`), (`fd6f2ce7f7046571`, `8d7d98c7b654f6b3`), (`41671ebe006f5bd4`, `328b6d7aa0940939`) and (`4a2396e4f9fea11b`, `f07838d26866e16b`). Pixel shaders `1bcc1a39c37f54eb` and `328b6d7aa0940939` (both from `/b6e28c40/0x38f972af.fdata`, IDRK@0x2f394788) hold KTGL's clustered-lighting loops: the cluster index comes from `gl_FragCoord`, the scene depth (slot 3) and the constants `c3[15..18]` (row and slice strides, z mapping); texel `2i` of the list in slot 16 is the cluster's offset into the index list and texel `2i + 1` packs two counts (`>> 16` and `& 0xffff`); each count bounds a do-while loop that reads a light index from the list and the light's data from slots 17 to 21. A count read from the wrong place (a float's bits give 16,000 or more) runs the loop that often per pixel and the GPU never returns. The vertex shaders have no loops; the other two pixel shaders have none. The pipeline of `1bcc1a39c37f54eb` compiled at the freeze differs from the one its draws use in the first battle only in the blend state (src alpha ONE, dst alpha ONE_MINUS_SRC_ALPHA): the same shader in another material pass, as the special's effect would use.
+- The list is a texture buffer of 1,012,000 R32 elements (NVN format `0xb`, serial 3013 in a headless run), zero copy over the pool, bound as 16,384-texel rows (`tbuf_as_2d`) and viewed as R32Float since the shader declares float ([Integer buffer textures read through float slots](../../../docs/reference/rendering.md#integer-buffer-textures-read-through-float-slots)). Checked on this Mac (M2 Pro): such a view returns every bit pattern unchanged, denormal and NaN ones included, and a read past the view's edge returns 0, so an index past the list cannot make a count. The slots 17 to 21 hold RGBA32Float buffers of 1,024 and 3,072 elements and R32 ones of 3,072 and 192; no compute dispatch writes the list (the game's CPU does), and all texture IDs the draws bind lie in the first of the game's two 33,024-entry descriptor pools.
+- Not reproduced: the first battle (the village, reached with the route under [Driving it on the Mac](#driving-it-on-the-mac)) draws those pixel shaders at 1x and at 2x and never hangs, but its list is empty in every dump taken (count 0 in every cluster), so the loops never ran there; the special attack's gauge never filled in the scripted rounds, and the outpost mission was not reached headless. The texel the loop read at the freeze is therefore still unknown.
+- The host now reports such a hang ([A GPU that never finishes: the hang watchdog](../../../docs/reference/rendering.md#a-gpu-that-never-finishes-the-hang-watchdog)): a `[RED] GPU watchdog` line names the pipelines of the submission the GPU is stuck on. To play on past a fragment shader it names, `DM_NVN_SKIP_FS=<key>` in `~/Library/Application Support/nxnative/04003F40232DE000/env.txt` drops its draws (the effect is missing, nothing else). Next: reach the outpost mission with the watchdog host, `DM_NVN_PASSDUMP_ALL=1` and `DM_NVN_CBDUMP` set, `passdump 3` and a `memdump` of the list right at the special (the scratch scripts `fight2.sh` / `lightlist.py` of the 2026-11-04 session do that), and compare the counts with the pixels' cluster indices.
+
 ## Saves
 
 - The save is one file, `DATA.BIN` (8 MB). A new save creates it at boot with its defaults (operation 0 of the game's file request routine, `main+0x1325be0`); every boot reads its header and three areas (operations 1, 6, 7 and 8).
@@ -43,7 +52,8 @@ Run headless: `DM_WINDOW` set to anything, `0` too, opens a window, and a covere
 ## Open
 
 - The long frames ([Performance](#performance)).
-- Battles, the picture against a Switch 2, an IPA (a full iOS shader build first).
+- [The GPU hang in a battle](#gpu-hang-in-a-battle-open): the outpost mission, with the special attack's light list dumped.
+- The picture against a Switch 2, an IPA (a full iOS shader build first).
 
 ## Found on this game
 
@@ -54,3 +64,4 @@ Run headless: `DM_WINDOW` set to anything, `0` too, opens a window, and a covere
 - [Dedicated c1 constants as slices of a bank](../../../docs/reference/frame-rate.md#dedicated-c1-constants-as-slices-of-a-bank): about 10 fps in the first field.
 - [Barrier moves around warp shuffles](../../../docs/reference/shaders.md#barrier-moves-around-warp-shuffles): two pixel shaders left out of the build.
 - [LDC with the bank in its address register (`.IS`)](../../../docs/reference/shaders.md#ldc-with-the-bank-in-its-address-register-is): two shaders left out of the build.
+- [A GPU that never finishes: the hang watchdog](../../../docs/reference/rendering.md#a-gpu-that-never-finishes-the-hang-watchdog): the freeze in the first outpost mission ([GPU hang in a battle](#gpu-hang-in-a-battle-open)).

dm/gfx/nvn/nvn_geometry.inc

@@ -603,6 +603,24 @@ static void mtk_encode(id<MTLRenderCommandEncoder> en_) {
 // DrawMeshTasksIndirect: {count, first}, which the game's culling writes earlier in the submission, while Metal's indirect mesh draw takes {x, y, z}. mdx_run copies the count to a {count, 1, 1} on the
 // GPU, before the render pass and for every such draw up to the next write, and the shader reads first from the record. Reading the record on the CPU instead took a wait for the GPU at each hazard:
 // 73 % of the submit thread in Ocarina of Time's Kokiri Forest, frames of 90 ms and more against 25 ms of GPU work
+// Diagnostic DM_NVN_MESHLOG_CB_GPU=1 (with DM_NVN_MESHLOG_CB, off by default): what the GPU reads, not what the CPU holds. Before a task draw the render pass is ended and the same four words are copied
+// in queue order into a host buffer (one slot per record and draw, set to 0xfeedface first, so a copy that never ran shows), which the failure report prints beside the CPU's. It splits the pass
+// at every task draw, so it can change what hangs: use it to see the value, not to count hangs. The slot is handed to subrec_mesh_words (g_mlcb_gw)
+static void mlcb_gpu_copy(NvShader *ts) {
+    static int on = -1, reg = -1; static uint32_t off; static __strong id<MTLBuffer> buf;
+    if (on < 0) { const char *g = getenv("DM_NVN_MESHLOG_CB_GPU"), *e = getenv("DM_NVN_MESHLOG_CB"); unsigned r, o; on = g && atoi(g) && e && sscanf(e, "%u:%u", &r, &o) == 2 && r < 16;
+        if (on) { reg = (int)r; off = o & ~3u; buf = [g_dev newBufferWithLength:(size_t)SUBREC_RING * SUBREC_MESH * 16 options:MTLResourceStorageModeShared]; if (buf) res_add(buf); else on = 0;   // res_add: a buffer a command writes must be in the residency set
+            MLOG("DM_NVN_MESHLOG_CB_GPU: the task stage's register %d at byte %u is copied by the GPU before each task draw (the render pass is split there)", reg, off); } }
+    g_mlcb_gw = NULL;
+    subrec_t *r = g_subrec_cur; if (!on || !ts || !r || r->nm >= SUBREC_MESH) return;
+    const p_bind_buf *u = &S.ubo[3][reg]; void *mb; uint64_t mo;
+    if (!u->addr || (uint64_t)off + 16 > u->size || !mtl_addr(u->addr + off, 16, &mb, &mo) || (g_nubd && ubd_hits(u->addr + off, u->addr + off + 16))) return;
+    uint32_t *slot = (uint32_t *)buf.contents + ((size_t)(r - g_subrec) * SUBREC_MESH + r->nm) * 4;
+    slot[0] = slot[1] = slot[2] = slot[3] = 0xfeedface;
+    rp_end();
+    enc_b_copy_buffer(blit_buf(u->addr + off, u->addr + off + 16, 0, 0), (__bridge id<MTLBuffer>)mb, (NSUInteger)mo, buf, (NSUInteger)((uint8_t *)slot - (uint8_t *)buf.contents), 16);
+    g_mlcb_gw = slot;
+}
 static void mesh_tasks_draw(const p_draw *dw) {
     if (!S.prog || (!dw->ind && dw->count <= 0)) return;
     // Diagnostic DM_NVN_SKIP_MESH=1 (off by default): drops every task / mesh draw, as DM_NVN_SKIP_FS drops draws by fragment shader, to measure what they cost in all (the picture is wrong)
@@ -614,6 +632,7 @@ static void mesh_tasks_draw(const p_draw *dw) {
         RED_ONCE(150, "DrawMeshTasks without its task and mesh shaders (task %s mesh %s): draw skipped", ts ? ts->key : "-", ms ? ms->key : "-"); return; }
     image_prepare(pr, 1u << 3 | 1u << 4);
     if (g_nubd && (g_enc || ubd_lazy()) && ((ts && ubd_conflict_sh(ts, 3)) || ubd_conflict_sh(ms, 4))) { g_ubd_conflicts++; rp_end(); ubd_land(); }   // as draw_ does for its stages
+    mlcb_gpu_copy(ts);   // DM_NVN_MESHLOG_CB_GPU
     NvProg *raster = pr->geo_lean_raster;   // the pixel stage alone
     if (!raster || raster->sh[1] != pr->sh[1] || raster->sh[0]) { raster = [NvProg new]; raster->sh[1] = pr->sh[1]; pr->geo_lean_raster = raster; }
     uint64_t ind = 0, ind_first = 0;
@@ -628,6 +647,11 @@ static void mesh_tasks_draw(const p_draw *dw) {
     draw_(&triangle, NULL);
     g_geo_program = nil; g_mtk.on = 0; args_dirty_all();
     if (g_mtk.miss) { g_mtk_wait++; return; }
+    // named if the command buffer fails (subrec_mesh_fmt): a direct draw's grid, a GPU-written one's count as the copy mdx_run made holds it when the report prints
+    subrec_mesh_add(ts ? ts->key : NULL, ms->key, pr->sh[1] ? pr->sh[1]->key : NULL, (uint32_t)dw->count, (uint32_t)dw->first, ind ? mdx_cpu(dw->ind, dw->ind) : NULL);
+    if (g_subrec_cur && g_subrec_cur->nm && g_subrec_cur->nm_more == 0) { subrec_mesh *me = &g_subrec_cur->m[g_subrec_cur->nm - 1]; me->no_first = 1; me->ind = dw->ind != 0;   // the copy holds {count, 1, 1}
+        if (ts) { subrec_mesh_words(S.ubo[3]);   // DM_NVN_MESHLOG_CB
+            if (me->has_words && g_nubd && ubd_hits(me->cb_addr + me->cb_off, me->cb_addr + me->cb_off + 16)) me->cb_state |= 1; } }   // an update deferred in the pass: the GPU reads its shadow, not these words
     swrite_note(pr); g_wr_epoch++;
     if (!g_mtk_n++) MLOG("task / mesh: first draw, task %s mesh %s fragment %s, %u workgroups from %u%s", ts ? ts->key : "-", ms->key, pr->sh[1] ? pr->sh[1]->key : "-", g_mtk.count, g_mtk.first, ind ? " (indirect)" : "");
 }