diff --git a/gpu/vk/vk_internal.h b/gpu/vk/vk_internal.h index 1c9169bf5..ef0707bd7 100644 --- a/gpu/vk/vk_internal.h +++ b/gpu/vk/vk_internal.h @@ -146,6 +146,9 @@ bool ub_read(uint64_t addr, void* dst, uint64_t n); /// [guest, guest + n) as of the submit being replayed: live itself, or scratch holding it with the kept pages over it const uint8_t* memory_as_submitted(uint64_t guest, const uint8_t* live, uint64_t n, std::vector& scratch); void memory_drop_shadow(uint64_t guest, uint64_t size); // (a write the capture did not take: the copies go) +/// (EvilBoyce) the newest submission value whose write-back reaches into [guest, guest + size) (0: none ever); *ever set +/// when any write-back ever did +uint64_t memory_writeback_value(uint64_t guest, uint64_t size, bool* ever); uint32_t memory_generation(); /// 1: a page of [guest, guest + size) was written after generation gen; 0: none was bool memory_written_since(uint64_t guest, uint64_t size, uint32_t gen); diff --git a/gpu/vk/vk_memory.cpp b/gpu/vk/vk_memory.cpp index 6545f8c33..4baac6947 100644 --- a/gpu/vk/vk_memory.cpp +++ b/gpu/vk/vk_memory.cpp @@ -772,6 +772,41 @@ void memory_drop_shadow(uint64_t guest, uint64_t size) { shadow_drop_range(guest, guest + size); } +// ---- (EvilBoyce) GPU results by page: the submission that last wrote a page into guest memory ---- +// For invalidate (vk_replay.cpp): a CPU read of GPU results waits until the submission that writes them there is done, as +// the console's coherent memory has them once that work is. Guest page number -> the recording's timeline value (write-backs +// from a mirror, and small bindings written in place). RX_VK_NO_READBACK_WAIT=1: none +namespace { +std::mutex wb_pages_mu; +std::unordered_map wb_pages; +uint64_t wb_pruned_at = 0; +void wb_pages_note(uint64_t guest_lo, uint64_t guest_hi, uint64_t value) { + static const bool off = getenv("RX_VK_NO_READBACK_WAIT") != nullptr; + if (off || !value || guest_hi <= guest_lo) return; + std::lock_guard lk(wb_pages_mu); + for (uint64_t p = guest_lo >> kPageShift; p <= (guest_hi - 1) >> kPageShift; p++) wb_pages[(uint32_t)p] = value; + if (wb_pages.size() > 200000 && mem_completed > wb_pruned_at) { // (the ones done long ago: kept as "ever" with value 1) + for (auto& kv : wb_pages) + if (kv.second <= mem_completed) kv.second = 1; + wb_pruned_at = mem_completed; + } +} +} // namespace +uint64_t memory_writeback_value(uint64_t guest, uint64_t size, bool* ever) { + uint64_t v = 0; + if (ever) *ever = false; + if (!size) return 0; + std::lock_guard lk(wb_pages_mu); + if (wb_pages.empty()) return 0; + for (uint64_t p = guest >> kPageShift; p <= (guest + size - 1) >> kPageShift; p++) { + auto it = wb_pages.find((uint32_t)p); + if (it == wb_pages.end()) continue; + if (ever) *ever = true; + v = std::max(v, it->second); + } + return v; +} + /// A copy that fails instead of faulting on a page unmapped meanwhile (structured exception handling: the common case /// costs a memcpy; ReadProcessMemory per page was ~2.3 us each). Not inlined, and the copy a call: without /// -fasync-exceptions clang catches a fault in a __try block only across a call, and a 4 KB memcpy inlined into the @@ -1537,6 +1572,8 @@ BufferRef gpu_buffer_bind(uint64_t gpu, uint64_t size, bool written) { auto& e = direct_by_pool[p->lo]; e.first++, e.second = (int)p->mstate; if (written) p->direct_write_epoch = mirror_epoch; + if (written && size <= (1u << 20)) // (EvilBoyce: GPU results written in place; small ones: the readbacks are) + wb_pages_note(p->lo + off, p->lo + std::min(off + size, p->hi - p->lo), mem_rec_value); return {p->buffer, off, size, 0}; } if (p->synced_epoch != mirror_epoch || p->sync_seg > texture_segment()) mirror_sync(*p); @@ -1818,6 +1855,7 @@ void memory_end_submission(VkCommandBuffer cmd) { checkpoint_mark(cmd, p->lo, 'b'); vkCmdCopyBuffer(cmd, p->mirror, p->buffer, (uint32_t)runs.size(), runs.data()); for (const VkBufferCopy& r : runs) st_wb_bytes += (int64_t)r.size; + for (const VkBufferCopy& r : runs) wb_pages_note(p->lo + r.dstOffset, p->lo + r.dstOffset + r.size, mem_rec_value); // (EvilBoyce) { // (hookshot) RX_VK_LOG_WRITEBACK=1: the pools written back the most, every 600 write-back submissions static const bool log_wb = getenv("RX_VK_LOG_WRITEBACK") != nullptr; if (log_wb) { diff --git a/gpu/vk/vk_replay.cpp b/gpu/vk/vk_replay.cpp index 7fc6bda29..b61710f53 100644 --- a/gpu/vk/vk_replay.cpp +++ b/gpu/vk/vk_replay.cpp @@ -1635,6 +1635,7 @@ bool tex_pages_any(uint64_t gpu, uint64_t size) { return false; } void texture_created_of(const nvn_tex* t) { tex_pages_add(t, +1); } +uint64_t fence(); void invalidate(uint64_t gpu, uint64_t size) { static const bool log_inv = getenv("RX_VK_LOG_INVALIDATE") != nullptr; static std::atomic logged{0}; @@ -1647,6 +1648,58 @@ void invalidate(uint64_t gpu, uint64_t size) { logf("vk: invalidate %#llx +%#llx:%s", (unsigned long long)gpu, (unsigned long long)size, hits.empty() ? " no texture the GPU wrote" : hits.c_str()); } + { // (EvilBoyce, diagnostics) RX_VK_LOG_READBACK=: from that present on, 300 invalidates with the fence handed + // out, the GPU's completed value, whether the replay is behind, and the first words the CPU is about to read + static const int64_t from = getenv("RX_VK_LOG_READBACK") ? atoll(getenv("RX_VK_LOG_READBACK")) : -1; + static std::atomic n{0}; + if (from >= 0 && presents_now >= from && n++ < 300) { + uint32_t w[8]{}; + host->gpu_read(gpu, w, sizeof w); + logf("vk: readback %lld %#llx +%#llx: fence %llu done %llu behind %d | %08x %08x %08x %08x %08x %08x %08x %08x", + (long long)presents_now, (unsigned long long)gpu, (unsigned long long)size, (unsigned long long)fence(), + (unsigned long long)completed(), (int)replay_behind(), w[0], w[1], w[2], w[3], w[4], w[5], w[6], w[7]); + } + } + // (EvilBoyce) GPU results in buffers: the CPU reads them once the submission that writes them back is done. The game + // reads them when its own pacing says the GPU has finished that frame, which on the console's coherent memory means the + // values are there; here they reach guest memory only with the write-back at the end of the submission that the replay + // may not have recorded or the GPU not finished yet. OoT reads its exposure meter (a sum the GPU adds to each frame and + // the CPU reads and sets to 0) this way: it read 0 one frame, then the old sum came back over the CPU's 0 and the next + // frame added to it (2x): the exposure stepped 0.2 EV up and down several times a second (the white flashes). + // RX_VK_NO_READBACK_WAIT=1: as before + if (size) { + static const bool off = getenv("RX_VK_NO_READBACK_WAIT") != nullptr; + bool ever = false; + if (!off && (memory_writeback_value(host->gpu_guest(gpu), size, &ever), ever)) { + static std::atomic calls{0}, waited{0}, ns{0}; + const auto w0 = std::chrono::steady_clock::now(); + bool w = false; + const uint64_t f0 = fence(), c0 = completed(); + const bool behind0 = replay_behind(); + static const bool no_catchup = getenv("RX_VK_READBACK_NO_CATCHUP") != nullptr; // (A/B: recorded work only) + if (behind0 && !no_catchup) wait_queue_empty(), w = true; // (work handed over may write it back too) + const auto w1 = std::chrono::steady_clock::now(); + const uint64_t v = memory_writeback_value(host->gpu_guest(gpu), size, nullptr); + if (v > completed()) wait_value(v), w = true; + if (w) { + waited++; + const int64_t d = std::chrono::duration_cast(std::chrono::steady_clock::now() - w0).count(); + ns += d; + static const bool log_each = getenv("RX_VK_LOG_READBACK_WAITS") != nullptr; + static std::atomic logged{0}; + if (log_each && presents_now > 4000 && logged++ < 300) + logf("vk: readback wait %lld %#llx +%#llx: %.2f ms (catch-up %.2f) value %llu, fence %llu, done %llu, behind %d", + (long long)presents_now, (unsigned long long)gpu, (unsigned long long)size, d / 1e6, + std::chrono::duration_cast(w1 - w0).count() / 1e6, (unsigned long long)v, + (unsigned long long)f0, (unsigned long long)c0, (int)behind0); + } + if (++calls % 3000 == 0) { + const int64_t n = waited.exchange(0); + logf("vk: readbacks of GPU results: %lld of 3000 waited for their write-back, %.2f ms each", (long long)n, + n ? ns.exchange(0) / (double)n / 1e6 : 0.0); + } + } + } // (textures the GPU wrote there: their texels into memory before the CPU reads it, as vmap_changing does. The game // waited for the work that wrote them; the replay is caught up first) { // (RX_VK_READBACK_OFF_FILE= (A/B): while that file exists, not) @@ -1983,6 +2036,21 @@ void do_present(const nvn_tex* t, const int crop[4]) { presents++; presents_now = presents; if (presents == 1) hang_watch_start(); + { // (EvilBoyce, diagnostics) RX_VK_WATCH_CPU=:[,...] (hex addresses): from that present on, the + // CPU's writes to those 4 KB pages logged with the writer's stack (host page watch: 12 reports) + static bool armed = false; + static const char* e = getenv("RX_VK_WATCH_CPU"); + if (e && !armed && host->watch_guest_writes && presents >= atoll(e)) { + armed = true; + for (const char* q = strchr(e, ':'); q && *q;) { + char* end; + const uint64_t a = strtoull(q + 1, &end, 16); + if (end == q + 1) break; + if (const uint64_t g = host->gpu_guest(a)) host->watch_guest_writes(g & ~4095ull, 4096); + q = *end ? end : nullptr; + } + } + } ts_anchor_ns = host->ticks() * 32; dump_present(presents); if (src && (dev.offscreen || shots) && offscreen_init()) { diff --git a/host/nvn_native.c b/host/nvn_native.c index 1b612ac98..e74e48c38 100644 --- a/host/nvn_native.c +++ b/host/nvn_native.c @@ -709,7 +709,8 @@ static LONG CALLBACK wts_handler(EXCEPTION_POINTERS *e) { static int all_threads = -1; /* RX_NVN_WATCH_ALL=1: the Resource Memory thread's writes too */ if (all_threads < 0) all_threads = getenv("RX_NVN_WATCH_ALL") != NULL; if ((all_threads || strcmp(tn, "Resource Memory")) && GetTickCount64() >= after && InterlockedIncrement(&wts_reports) <= 12) { /* (not the allocation's zero fill) */ - hos_log("nvn: write to a WriteTexels source at guest %#llx by %s", (unsigned long long)(a - (uintptr_t)GP(0)), tn); + hos_log("nvn: write to a WriteTexels source at guest %#llx by %s (host pc exe+%#llx)", (unsigned long long)(a - (uintptr_t)GP(0)), tn, + (unsigned long long)((uintptr_t)e->ExceptionRecord->ExceptionAddress - (uintptr_t)GetModuleHandleA(NULL))); hos_backtrace(); } DWORD old; diff --git a/readme.md b/readme.md index ec3db83a2..9632dea48 100644 --- a/readme.md +++ b/readme.md @@ -201,6 +201,8 @@ Bigger ways to help: Hookshot exists thanks to the work of many people: - **NotRexed**: Hookshot, BlueShell (Mario Kart World), Skybound (Tears of the Kingdom) and the a64-kit tools. +- **EvilBoyce** (Discord: evilmfkr, [fork](https://github.com/evilmfkr/Hookshot)): Ocarina of Time's foliage culling, ambient + light, water and fog fixes, the freeze after Load, the exposure flashes, and the rendering diagnostics tools. - **[Eden](https://git.eden-emu.dev/eden-emu/eden)** and **Eglantine**: the shader recompiler and Switch 2 shader work. - **suyu**: the graphics decoders and the AArch64 translator. - **[seedds/nxnative](https://github.com/seedds/nxnative)**: reference for how task and mesh shaders work.