diff --git a/dm/gfx/nvn/nvn_mtl.m b/dm/gfx/nvn/nvn_mtl.m index e3f6ea3..44072a1 100644 --- a/dm/gfx/nvn/nvn_mtl.m +++ b/dm/gfx/nvn/nvn_mtl.m @@ -98,6 +98,11 @@ static uint64_t g_vbuf_resolve, g_vbuf_reuse, g_vbuf_set, g_vbuf_skip; static id g_present_args; static id g_present_uv[3]; static uint64_t g_present_alloc_fence[3]; +// Under g_pq_mu: per present allocator, the newest ticket its commit feedback reported done on the GPU. present_now resets an allocator only once this reaches the ticket that +// last used it. g_pq_done is not that: every display-link callback sets it to ticket - 1 (the previous present was committed, not run) and a present that was not submitted sets +// it to its own ticket. Waiting on g_pq_done, a display-link present never waited here: with three presents in flight, or two after a dropped frame, the allocator was reset +// under a present the GPU had not run, and that present's drawable read back black (t_present_alloc; docs/reference/frame-rate.md) +static uint64_t g_present_alloc_done[3]; static pthread_mutex_t g_pq_mu = PTHREAD_MUTEX_INITIALIZER; static pthread_cond_t g_pq_cv = PTHREAD_COND_INITIALIZER; static pthread_cond_t g_link_cv = PTHREAD_COND_INITIALIZER; @@ -9939,7 +9944,7 @@ static int present_now(const tex_t *t, double period, uint64_t frame, uint64_t t int alloc_i = (int)(ticket % 3); if (g_present_alloc_fence[alloc_i]) { pthread_mutex_lock(&g_pq_mu); - while (g_pq_done < g_present_alloc_fence[alloc_i]) pthread_cond_wait(&g_pq_cv, &g_pq_mu); + while (g_present_alloc_done[alloc_i] < g_present_alloc_fence[alloc_i]) pthread_cond_wait(&g_pq_cv, &g_pq_mu); pthread_mutex_unlock(&g_pq_mu); } [g_present_alloc4[alloc_i] reset]; @@ -9953,7 +9958,7 @@ static int present_now(const tex_t *t, double period, uint64_t frame, uint64_t t MTL4CommitOptions *o = [MTL4CommitOptions new]; [o addFeedbackHandler:^(id f) { if (f.error) MLOG("[RED] display command buffer error: %s", f.error.description.UTF8String); - pthread_mutex_lock(&g_pq_mu); if (ticket > g_pq_done) g_pq_done = ticket; g_pq_inflight--; pthread_cond_broadcast(&g_pq_cv); + pthread_mutex_lock(&g_pq_mu); if (ticket > g_pq_done) g_pq_done = ticket; if (ticket > g_present_alloc_done[alloc_i]) g_present_alloc_done[alloc_i] = ticket; g_pq_inflight--; pthread_cond_broadcast(&g_pq_cv); present_gpu_note(f.GPUEndTime - f.GPUStartTime, fx_kind); pthread_mutex_unlock(&g_pq_mu); }]; id buffers[] = {cb}; diff --git a/dm/gfx/tests/.gitignore b/dm/gfx/tests/.gitignore index d9a5904..8839897 100644 --- a/dm/gfx/tests/.gitignore +++ b/dm/gfx/tests/.gitignore @@ -34,6 +34,8 @@ t_present_crop t_present_crop.dSYM/ t_present_rescue t_present_rescue.dSYM/ +t_present_alloc +t_present_alloc.dSYM/ t_reorder_chain t_reorder_chain.dSYM/ t_mip_extent diff --git a/dm/gfx/tests/Makefile b/dm/gfx/tests/Makefile index cfa72c9..73d4c87 100644 --- a/dm/gfx/tests/Makefile +++ b/dm/gfx/tests/Makefile @@ -106,6 +106,12 @@ t_present_rescue: t_present_rescue.m t_present_rescue_focus.c $(MTL_T_DEP) check_t_present_rescue: t_present_rescue MTL_DEBUG_LAYER=1 ./t_present_rescue --metal run: check_t_present_rescue +t_present_alloc: t_present_alloc.m $(MTL_T_DEP) + clang $(CFLAGS) -fobjc-arc -o $@ t_present_alloc.m $(MTL_T_SRC) $(FW) +.PHONY: check_t_present_alloc +check_t_present_alloc: t_present_alloc + MTL_DEBUG_LAYER=1 ./t_present_alloc +run: check_t_present_alloc t_present_snap: t_present_snap.m $(MTL_T_DEP) clang $(CFLAGS) -fobjc-arc -o $@ t_present_snap.m ../../host/crash.c ../../host/hle_bigstack.c t_host_stubs.c $(filter-out ../nvn/nvn_mtl.m,$(GFX)) $(FW) .PHONY: check_t_present_snap diff --git a/dm/gfx/tests/t_present_alloc.m b/dm/gfx/tests/t_present_alloc.m new file mode 100644 index 0000000..a1ac5eb --- /dev/null +++ b/dm/gfx/tests/t_present_alloc.m @@ -0,0 +1,113 @@ +// Display-link presents with the GPU held back: a present must not reset a command allocator whose own present has not run yet. Real Metal 4 queue and offscreen +// drawables; the link's callback is called by hand (no window, no game files). Two cases: a dropped frame (two presents in flight) and one frame per tick (three in flight). +#include "../nvn/nvn_mtl.m" +@interface FakeLinkUpdate : NSObject +@property id drawable; +@property CFTimeInterval targetPresentationTimestamp; +@end +@implementation FakeLinkUpdate +@end +static CAMetalLayer *g_test_layer; +void *front_metal_layer(void) { return (__bridge void *)g_test_layer; } +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(name, ok) do { int pass = !!(ok); checks++; failed += !pass; printf("%s: %s\n", name, pass ? "PASS" : "FAIL"); } while (0) +static tex_t source(unsigned serial, uint8_t left, uint8_t right) { // 8x8 grey, the left four columns one value and the right four another + MTLTextureDescriptor *d = [MTLTextureDescriptor texture2DDescriptorWithPixelFormat:MTLPixelFormatRGBA8Unorm width:8 height:8 mipmapped:NO]; + d.storageMode = MTLStorageModeShared; d.usage = MTLTextureUsageShaderRead; + id mt = [g_dev newTextureWithDescriptor:d]; uint8_t bytes[256]; + for (int i = 0; i < 64; i++) { uint8_t v = i % 8 < 4 ? left : right; bytes[4 * i] = bytes[4 * i + 1] = bytes[4 * i + 2] = v; bytes[4 * i + 3] = 255; } + [mt replaceRegion:MTLRegionMake2D(0, 0, 8, 8) mipmapLevel:0 withBytes:bytes bytesPerRow:32]; + tex_t t = {.magic=MAGIC('T','E','X',0), .serial=serial}; + t.d.width = t.d.height = 8; t.d.depth = t.d.levels = t.d.samples = 1; + t.d.target = NVN_TEXTURE_TARGET_2D; t.d.format = NVN_FORMAT_RGBA8; + serial_put(t.serial, mt); res_add(mt); res_commit(); return t; +} +static CAMetalLayer *offscreen_layer(void) { + CAMetalLayer *l = [CAMetalLayer layer]; l.device = g_dev; l.pixelFormat = MTLPixelFormatBGRA8Unorm; l.framebufferOnly = NO; l.drawableSize = CGSizeMake(8, 8); return l; +} +// Every present gets a drawable of its own layer. With all drawables from one offscreen layer, 1 of 100 runs under CPU load got ticket 1's IOSurface back from +// nextDrawable while the gate still held ticket 1's present, and ticket 4 then drew over the picture this test reads back +static NSMutableArray *g_layers; +static id drawable(void) { + CAMetalLayer *l = offscreen_layer(); [g_q4 addResidencySet:l.residencySet]; [g_layers addObject:l]; return [l nextDrawable]; +} +static NvMetalDisplayLinkDelegate *g_delegate; +static id tick_with(id dr) { // one display-link callback (it does not look at the link) + FakeLinkUpdate *u = [FakeLinkUpdate new]; u.drawable = dr; u.targetPresentationTimestamp = CACurrentMediaTime() + 0.016; + [g_delegate metalDisplayLink:(CAMetalDisplayLink *)(id)u needsUpdate:(CAMetalDisplayLinkUpdate *)u]; + return dr; +} +static id tick(void) { return tick_with(drawable()); } +// The tick that lands on a used allocator runs on its own thread, so the test sees whether it waits; its drawable is taken before the thread starts +static id g_held; static dispatch_semaphore_t g_held_done; +static void *held_tick(void *arg) { (void)arg; @autoreleasepool { tick_with(g_held); } dispatch_semaphore_signal(g_held_done); return NULL; } +static void reuse_case(id dr, id gate, uint64_t open, uint64_t ticket, int inflight, uint64_t old) { + char name[160]; + g_held = dr; g_held_done = dispatch_semaphore_create(0); pthread_t th; pthread_create(&th, NULL, held_tick, NULL); + int returned = dispatch_semaphore_wait(g_held_done, dispatch_time(DISPATCH_TIME_NOW, 300 * NSEC_PER_MSEC)) == 0; + pthread_mutex_lock(&g_pq_mu); int inside = g_pq_read == ticket && g_pq_inflight == inflight; pthread_mutex_unlock(&g_pq_mu); + snprintf(name, sizeof name, "ticket %llu reached present_now", (unsigned long long)ticket); CHECK(name, returned || inside); + snprintf(name, sizeof name, "allocator %llu is not reused while ticket %llu is on the GPU", (unsigned long long)(ticket % 3), (unsigned long long)old); CHECK(name, !returned); + gate.signaledValue = open; + if (!returned) returned = dispatch_semaphore_wait(g_held_done, dispatch_time(DISPATCH_TIME_NOW, 5 * NSEC_PER_SEC)) == 0; + snprintf(name, sizeof name, "ticket %llu is presented once the GPU gets to ticket %llu", (unsigned long long)ticket, (unsigned long long)old); CHECK(name, returned); + pthread_join(th, NULL); + pthread_mutex_lock(&g_pq_mu); struct timespec ts; clock_gettime(CLOCK_REALTIME, &ts); ts.tv_sec += 5; + while (g_pq_inflight && pthread_cond_timedwait(&g_pq_cv, &g_pq_mu, &ts) != ETIMEDOUT) {} + int left = g_pq_inflight; uint64_t done = g_pq_done; pthread_mutex_unlock(&g_pq_mu); + CHECK("every present completed", left == 0 && done == ticket); +} +static int bad_pixels(id t, uint8_t left, uint8_t right) { + id out = [g_dev newBufferWithLength:256 options:MTLResourceStorageModeShared]; + id cb = [g_q commandBuffer]; id b = [cb blitCommandEncoder]; + [b copyFromTexture:t sourceSlice:0 sourceLevel:0 sourceOrigin:MTLOriginMake(0, 0, 0) sourceSize:MTLSizeMake(8, 8, 1) + toBuffer:out destinationOffset:0 destinationBytesPerRow:32 destinationBytesPerImage:256]; + [b endEncoding]; [cb commit]; [cb waitUntilCompleted]; + const uint8_t *p = out.contents; int bad = 0; + for (int i = 0; i < 64; i++) { uint8_t v = i % 8 < 4 ? left : right; bad += p[4 * i] != v || p[4 * i + 1] != v || p[4 * i + 2] != v; } + if (bad) { printf("first row:"); for (int i = 0; i < 8; i++) printf(" %u", p[4 * i]); printf(" (want %u x4, %u x4)\n", left, right); } + return bad; +} +int main(void) { @autoreleasepool { + alarm(30); setbuf(stdout, NULL); + setenv("DM_PRESENT_HZ", "0", 1); + mtl_init(); + g_test_layer = offscreen_layer(); g_layers = [NSMutableArray new]; + // Display-link mode without a link thread: link_sync sees a started link that is not there yet, the present thread leaves the queue to the callback + g_dm_present_link = 1; g_link_started = 1; g_link_owns_layer = 1; g_delegate = [NvMetalDisplayLinkDelegate new]; + tex_t a = source(91001, 50, 150), b = source(91002, 100, 100), c = source(91003, 200, 200); + static const int left_half[4] = {0, 0, 4, 8}; + id gate = [g_dev newSharedEvent]; + // Every callback moves g_pq_done to ticket - 1, so it is no guard for the allocator: the presents below wait only if the allocator's own completion is checked. + // On main both cases fail the reuse check, and the earlier ticket's drawable reads back black (0 in every pixel): its command buffer was encoded again before the GPU ran it + + // A dropped frame: ticket 1 on allocator 1, then 3 (2 dropped) on allocator 0, then 4 on allocator 1 again with two presents in flight + [g_q4 waitForEvent:gate value:1]; // nothing committed to the Metal 4 queue from here runs until the gate opens + present_enqueue(&a, 1. / 60, NULL, 0); + id first = tick(); + present_enqueue(&b, 1. / 60, NULL, 0); present_enqueue(&b, 1. / 60, NULL, 0); present_enqueue(&c, 1. / 60, left_half, 0); + tick(); + printf("after the drop: read %llu, done %llu, in flight %d\n", (unsigned long long)g_pq_read, (unsigned long long)g_pq_done, g_pq_inflight); + CHECK("ticket 1 has not completed", g_pq_inflight == 2); + reuse_case(drawable(), gate, 1, 4, 2, 1); + int bad = bad_pixels(first.texture, 50, 150); printf("ticket 1 drawable: %d of 64 pixels wrong\n", bad); + CHECK("ticket 1 shows its own picture", bad == 0); + + // One frame per tick, nothing dropped: tickets 5, 6 and 7 on allocators 2, 0 and 1, then 8 on allocator 2 again with three presents in flight + [g_q4 waitForEvent:gate value:2]; + present_enqueue(&a, 1. / 60, NULL, 0); id fifth = tick(); + present_enqueue(&b, 1. / 60, NULL, 0); tick(); + present_enqueue(&b, 1. / 60, NULL, 0); tick(); + present_enqueue(&c, 1. / 60, left_half, 0); + printf("one per tick: read %llu, done %llu, in flight %d, dropped %llu\n", (unsigned long long)g_pq_read, (unsigned long long)g_pq_done, g_pq_inflight, (unsigned long long)g_link_dropped); + CHECK("tickets 5-7 have not completed", g_pq_inflight == 3 && g_link_dropped == 1); + reuse_case(drawable(), gate, 2, 8, 3, 5); + CHECK("no frame dropped after ticket 2", g_link_dropped == 1); + bad = bad_pixels(fifth.texture, 50, 150); printf("ticket 5 drawable: %d of 64 pixels wrong\n", bad); + CHECK("ticket 5 shows its own picture", bad == 0); + printf("present allocators: %d checks, %d failed\n", checks, failed); return failed != 0; +} } diff --git a/docs/agents/symptoms.md b/docs/agents/symptoms.md index 0b45384..9ea37f1 100644 --- a/docs/agents/symptoms.md +++ b/docs/agents/symptoms.md @@ -220,6 +220,7 @@ One line per symptom in the [subsystem references](../reference/): what you see - the game presents at interval 1, yet every frame takes exactly 33.3 ms of "frame work"; after only the limiter was raised, everything ran twice as fast on the iPhone. → [A render-thread limiter with a constant and a fixed time step](../reference/frame-rate.md#a-render-thread-limiter-with-a-constant-and-a-fixed-time-step) - 55 fps with every frame 18.2 ms, the main thread asleep most of the time; every 11th frame stays on screen two vsyncs. → [A frame-end wait polled in 2 ms sleeps](../reference/frame-rate.md#a-frame-end-wait-polled-in-2-ms-sleeps) - the app is active and the game keeps running, but the picture freezes while display-link callbacks stop; the log repeatedly drops queued frames. → [Present thread rescues a silent display link](../reference/frame-rate.md#present-thread-rescues-a-silent-display-link) +- with the display link driving presents, a presented frame comes out black when three presents are on the GPU at once, or two after a dropped frame; on an M6 the same reuse also logs `[RED] display command buffer error` with `kIOGPUCommandBufferCallbackErrorPageFault`. → [A present command allocator is reused only after its own present completes](../reference/frame-rate.md#a-present-command-allocator-is-reused-only-after-its-own-present-completes) - "sometimes the speed increases when jumping" (Mario 1.2.1 on the iPhone): in `display` mode interval-2 frames were shown for 16.7 ms and the game visibly jumped ahead. "When pressing B, Link's move pace is speeding up" (Breath of the Wild on the iPhone); `old frames dropped by merging`. → [Frames of a dynamic present interval held on screen and at the acquire](../reference/frame-rate.md#frames-of-a-dynamic-present-interval-held-on-screen-and-at-the-acquire) - frames miss the screen while the GPU stays at its lowest clock (444 MHz on an M2 Max); more work (a higher render scale) only makes the frames slower. → [Present snapshots: the game's swapchain texture free at once](../reference/frame-rate.md#present-snapshots-the-games-swapchain-texture-free-at-once) - a steady game whose frame-rate counter wanders between 50 and 60 on the iPhone only; the `display link up to tick` lines show about as many empty ticks as frames dropped by merging: frames arrive two in one tick and none in the next. → [Vulkan acquire and vsync event follow the display link](../reference/frame-rate.md#vulkan-acquire-and-vsync-event-follow-the-display-link) diff --git a/docs/reference/frame-rate.md b/docs/reference/frame-rate.md index df38ea0..fbbbf2a 100644 --- a/docs/reference/frame-rate.md +++ b/docs/reference/frame-rate.md @@ -66,6 +66,15 @@ Frame pacing: the host's frame step, engine frame limiters, present intervals an - **Check:** `make -C dm/gfx/tests GAME=010015100B514000 t_present_rescue` and `dm/gfx/tests/t_present_rescue` exercise the production wait and retry paths with a controlled clock and a silent link double, without a GPU. They cover foreground grace, backoff saturation, runtime mode changes, and layer release only after run-loop invalidation. The test also runs in CPU graphics CI. `make -C dm/gfx/tests GAME=010015100B514000 check_t_present_rescue` adds a paused real Metal display link on an offscreen Mac layer: rescue invalidates it, then `nextDrawable` succeeds (47 checks, zero failures with Metal validation). `DM_TEST_LINK_STALL=,` pauses a real window's display link for manual verification. - **Not checked:** gameplay during stalled-link recovery or the iPhone; the PR's gameplay runs were headless. +### A present command allocator is reused only after its own present completes + +- **Symptom:** with the display link driving presents, a presented frame comes out black when three presents are on the GPU at once, or two after a dropped frame; on an M6 the same reuse also logs `[RED] display command buffer error` with `kIOGPUCommandBufferCallbackErrorPageFault`. +- **Cause:** `present_now` cycles three Metal 4 command allocators, each with its command buffer and UV buffer, by ticket, and before resetting one it waited for `g_pq_done` to reach the ticket that last used it. `g_pq_done` is not GPU completion: every display-link callback sets it to `ticket - 1` (the previous present was committed, not run), and a present that was not submitted sets it to its own ticket. So a display-link present never waited there. With three presents in flight, or two after a dropped frame, the allocator was reset and its command buffer encoded again under a present the GPU had not run, and that present's drawable read back black. +- **Fix:** each allocator keeps the newest ticket its own commit feedback has reported (`g_present_alloc_done`), and its reuse waits for that. The display-link callback can now block in `present_now` until the GPU has run the allocator's previous present. `g_pq_done` keeps its meaning for the game's swapchain acquire. +- **Found on:** no game. Found by reading `NvMetalDisplayLinkDelegate`, then reproduced in `t_present_alloc` (below). +- **Check:** `make -C dm/gfx/tests GAME=010015100B514000 check_t_present_alloc` holds the Metal 4 queue behind a shared event and calls the display-link callback by hand, each present with a drawable of its own offscreen layer. It covers a dropped frame (tickets 1, 3, then 4 on allocator 1 again) and one frame per tick (5, 6, 7, then 8 on allocator 2 again). Before the fix, in both cases the reusing present returns while the earlier one is held and the earlier drawable reads back 0 in all 64 pixels (4 of 13 checks fail; on an M6 every run also logs the GPU page fault); with it the reusing present waits until the gate opens, and all 13 checks pass with Metal validation. +- **Not checked:** a game run hitting it, the iPhone, and the not-submitted path, which the test does not exercise. + ### Frames of a dynamic present interval held on screen and at the acquire - **Symptom:** "sometimes the speed increases when jumping" (Mario 1.2.1 on the iPhone): in `display` mode interval-2 frames were shown for 16.7 ms and the game visibly jumped ahead. "When pressing B, Link's move pace is speeding up" (Breath of the Wild on the iPhone); `old frames dropped by merging`.