From 74b9687a8f4ef4d8da23516daa0461d1eb6e5386 Mon Sep 17 00:00:00 2001 From: chrg6 Date: Fri, 13 Nov 2026 17:22:18 -0500 Subject: [PATCH] Time VMA's device memory allocations in the trace's work marks. An area's first visit (0.10.0 fresh session, nx2navi.1.log, frame 10113) took 421 ms, and the stutter line left 192 ms of it as replay and 27.5 ms unattributed after the pipeline, translation and texture waits. The same frame made 78 device memory allocations of 4442.7 MiB, but the "device memory allocations" mark carried only a count and bytes: vk_headroom.c on_allocate added it with zero time, since VMA's allocate callback runs after the allocation. At the 8-19 ms per 256 MiB block that vk_headroom.c measured, those allocations could be most of the frame's unexplained time. vk_device.c create_device now hands VMA a VmaVulkanFunctions whose only member is vkAllocateMemory = timed_alloc; VMA takes the others from its static table (vk_vma.cpp VMA_STATIC_VULKAN_FUNCTIONS 1; its ImportVulkanFunctions copies only the non-null members). timed_alloc brackets vkAllocateMemory with perf_mark_begin and perf_mark_end, which cost one branch while the trace is off. on_allocate's zero-time mark is gone, and perf.c mark_text prints the allocations' time, count, bytes and longest like the other kinds. The texture statistics' count of large allocations is left as it is (adding the time there would have counted every allocation a second time). Diagnostics only, no change to play. Not reproduced before the change (it needs an area load with trace=perf). stutter_map_check, stutter_hitch_check, frame_step_check and mem_growth_check pass; every runtime file compiles with the dev flags after the host.h comment change, and vk_device.c, vk_headroom.c and perf.c add no -Wall -Wextra warnings. Co-Authored-By: Claude Opus 5.5 --- runtime/host.h | 4 ++-- runtime/perf.c | 10 +++------- runtime/vk_device.c | 15 ++++++++++++++- runtime/vk_headroom.c | 3 +-- 4 files changed, 20 insertions(+), 12 deletions(-) diff --git a/runtime/host.h b/runtime/host.h index d84c502c..97c68b5c 100644 --- a/runtime/host.h +++ b/runtime/host.h @@ -56,8 +56,8 @@ void perf_count(int kind); // NX2NAVI_TRACE=perf: work on any thread that a frame can wait for besides the render thread's waits above, summed per // frame and per 60-frame window (perf.c perf_mark_add): RomFS reads, host zstd decodes, pipeline creates (vk_pipeline.c // pipe_create_in), guest memory maps (heap size, MapPhysicalMemory), NVN memory pool initialize and finalize -// (vk_memory.c vk_pool_init, vk_pool_fini), device memory VMA allocates (blocks and dedicated memory: count and -// bytes, no time), and DLSS and DLSS frame generation feature creates (vk_dlaa.c). perf_mark_begin returns 0 while the trace is off, so a normal run pays one branch per site. +// (vk_memory.c vk_pool_init, vk_pool_fini), device memory VMA allocates (blocks and dedicated memory, vk_device.c +// timed_alloc), and DLSS and DLSS frame generation feature creates (vk_dlaa.c). perf_mark_begin returns 0 while the trace is off, so a normal run pays one branch per site. enum { PERF_M_FILE, PERF_M_ZSTD, PERF_M_PIPE, PERF_M_GMEM, PERF_M_POOL, PERF_M_DEVMEM, PERF_M_NGX, PERF_M_N }; uint64_t perf_mark_begin(void); void perf_mark_end(int kind, uint64_t t0, uint64_t bytes); // nothing when t0 is 0 diff --git a/runtime/perf.c b/runtime/perf.c index 9b94583b..022b771f 100644 --- a/runtime/perf.c +++ b/runtime/perf.c @@ -182,17 +182,13 @@ static void mark_frame(MarkSums *f) { } // "; on any thread: file reads 12.3 ms (40, 5.1 MiB, longest 2.0 ms), ..." for the kinds with work, appended at line + n. -// Device memory allocations carry no time. static int mark_text(const MarkSums *s, char *line, int n, size_t cap) { int any = 0; for (int k = 0; k < PERF_M_N && n >= 0 && n < (int)cap - 100; k++) { if (!s->n[k]) continue; - n += snprintf(line + n, cap - (size_t)n, "%s %s", any ? "," : "; on any thread:", mark_name[k]); - if (k == PERF_M_DEVMEM) - n += snprintf(line + n, cap - (size_t)n, " %llu (%.1f MiB)", (unsigned long long)s->n[k], s->bytes[k] / 1048576.0); - else - n += snprintf(line + n, cap - (size_t)n, " %.1f ms (%llu, %.1f MiB, longest %.1f ms)", s->ns[k] / 1e6, - (unsigned long long)s->n[k], s->bytes[k] / 1048576.0, s->max[k] / 1e6); + n += snprintf(line + n, cap - (size_t)n, "%s %s %.1f ms (%llu, %.1f MiB, longest %.1f ms)", + any ? "," : "; on any thread:", mark_name[k], s->ns[k] / 1e6, (unsigned long long)s->n[k], + s->bytes[k] / 1048576.0, s->max[k] / 1e6); any = 1; } return n; diff --git a/runtime/vk_device.c b/runtime/vk_device.c index 24741a53..5fd4ef82 100644 --- a/runtime/vk_device.c +++ b/runtime/vk_device.c @@ -432,6 +432,18 @@ static void fatal_note(void) { g_mesh_path); } +// NX2NAVI_TRACE=perf: every device memory allocation VMA makes, timed as the "device memory allocations" work mark +// (perf.c mark_text). An area's first visit made 78 of them, 4.4 GB, in a frame of 421 ms of which about 180 ms +// showed in no mark; vk_headroom.c measured 8-19 ms per 256 MiB block. VMA takes this one function from the +// allocator's create info and the others from its static table (vk_vma.cpp VMA_STATIC_VULKAN_FUNCTIONS). +static VkResult VKAPI_PTR timed_alloc(VkDevice d, const VkMemoryAllocateInfo *ai, const VkAllocationCallbacks *cb, + VkDeviceMemory *m) { + uint64_t t0 = perf_mark_begin(); + VkResult r = vkAllocateMemory(d, ai, cb, m); + perf_mark_end(PERF_M_DEVMEM, t0, r == VK_SUCCESS ? ai->allocationSize : 0); + return r; +} + static int create_device(void) { uint32_t ne = 0; vkEnumerateDeviceExtensionProperties(g_vk.phys, NULL, &ne, NULL); @@ -721,12 +733,13 @@ static int create_device(void) { vk_mem_lazy_decide(); // the driver is known: the lazy write-back's default depends on it rt_fatal_note_add(fatal_note); + static const VmaVulkanFunctions vf = {.vkAllocateMemory = timed_alloc}; // the rest from VMA's static table VmaAllocatorCreateInfo ai = {.physicalDevice = g_vk.phys, .device = g_vk.device, .instance = g_vk.instance, .vulkanApiVersion = VK_API_VERSION_1_3, .flags = (g_vk.has_buffer_device_address ? VMA_ALLOCATOR_CREATE_BUFFER_DEVICE_ADDRESS_BIT : 0) | (g_vk.has_memory_budget ? VMA_ALLOCATOR_CREATE_EXT_MEMORY_BUDGET_BIT : 0), .preferredLargeHeapBlockSize = vk_vma_block_size(), - .pDeviceMemoryCallbacks = vk_headroom_callbacks()}; + .pDeviceMemoryCallbacks = vk_headroom_callbacks(), .pVulkanFunctions = &vf}; VkDeviceSize heap_limit[VK_MAX_MEMORY_HEAPS]; if (vram_heap_limits(heap_limit)) ai.pHeapSizeLimit = heap_limit; if ((r = vmaCreateAllocator(&ai, &g_vk.vma)) != VK_SUCCESS) { rt_log("vk: vmaCreateAllocator failed (%d)", (int)r); return 0; } diff --git a/runtime/vk_headroom.c b/runtime/vk_headroom.c index fe712a0c..a49fd9f6 100644 --- a/runtime/vk_headroom.c +++ b/runtime/vk_headroom.c @@ -83,8 +83,7 @@ static int spare_type(const VkCtx *c, uint32_t type) { uint64_t vk_headroom_held(void) { return (uint64_t)__atomic_load_n(&H.held, __ATOMIC_RELAXED); } static void VKAPI_PTR on_allocate(VmaAllocator a, uint32_t type, VkDeviceMemory m, VkDeviceSize size, void *user) { - (void)a, (void)m, (void)size, (void)user; - perf_mark_add(PERF_M_DEVMEM, 0, size); // NX2NAVI_TRACE=perf: every block and dedicated allocation VMA makes + (void)a, (void)m, (void)size, (void)user; // the trace's mark of the allocation, with its time: vk_device.c timed_alloc if (!H.on || type >= 64) return; if (plat_thread_id() == H.tid) { plat_inc64(&H.made);