From c4c7078afcee641e4c431fc8ae9f3e421390fd42 Mon Sep 17 00:00:00 2001 From: iChris4 Date: Sun, 20 Sep 2026 17:10:00 +0200 Subject: [PATCH] Enhance texture management and profiling in GX thread; add reinitialization flag and optimize consumer behavior --- aurora-main/lib/aurora.cpp | 4 + docs/quest-port.md | 17 ++++ runtime/src/hle/gx/gx_internal.h | 5 ++ runtime/src/hle/gx/gx_texture.cpp | 11 ++- runtime/src/hle/gx/gx_thread.cpp | 131 ++++++++++++++++++++++++++---- 5 files changed, 148 insertions(+), 20 deletions(-) diff --git a/aurora-main/lib/aurora.cpp b/aurora-main/lib/aurora.cpp index 95ecf97..98efd71 100644 --- a/aurora-main/lib/aurora.cpp +++ b/aurora-main/lib/aurora.cpp @@ -28,6 +28,7 @@ #include "gfx/pipeline_cache.hpp" #endif #if defined(__ANDROID__) +#include #include #endif #include "system_info.hpp" @@ -355,6 +356,9 @@ void frame_worker_main() noexcept { } #if defined(__ANDROID__) g_frameWorkerNativeThreadId.store(static_cast(gettid()), std::memory_order_release); + // A thread inherits its creator's name, and the producer that starts this + // worker may itself be a named thread; profiles should tell the two apart. + pthread_setname_np(pthread_self(), "aurora worker"); #endif #ifdef AURORA_ENABLE_GX diff --git a/docs/quest-port.md b/docs/quest-port.md index 1326fd1..3b2bc95 100644 --- a/docs/quest-port.md +++ b/docs/quest-port.md @@ -723,6 +723,23 @@ waited under 0.1 ms per frame in its two `GXDrawDone` drains and never for ring space, and the GX thread was 25 to 40% busy. Retro Rewind's menus were unaffected (prewarm 5.2 s, 60 fps). +Two things the first day on it taught. The Retro Rewind menu with the blurred +background fell to 14 to 18 fps, with the GX thread on or off, and the +per-record profile that the `fpslog` line now carries (`costliest:`) put it +all in the FIFO records: the game re-initialises its capture texture objects +every frame, and the split had kept one aurora object per guest object alive +across those re-initialisations, so `GXInitTexObjData` kept incrementing +`texDataVersion`, which is part of aurora's static upload key, and every +frame converted every such texture again (`convert_texture` 18% of the +thread). A guest `GXInitTexObj` now rebuilds the aurora object, as it always +had, so the version restarts and the upload cache hits. Second, that menu +calls `GXDrawDone` 22 to 24 times per frame (the base main menu 9 times), +and each drain cost about 1.5 ms while the game thread slept on a condition +variable: both the drain and the idle consumer now spin for a few hundred +microseconds before blocking, with a sequentially consistent sleep handshake, +and the 22 drains cost 2.6 ms per frame in total; that screen runs at 60 with +the thread on. + Verified on device since: the menus on the virtual screen, controller input (the user has driven races), and an immersive Grand Prix start with all 12 racers rendering correctly. Not yet verified: stereo comfort and scale, diff --git a/runtime/src/hle/gx/gx_internal.h b/runtime/src/hle/gx/gx_internal.h index 7007944..5b46ceb 100644 --- a/runtime/src/hle/gx/gx_internal.h +++ b/runtime/src/hle/gx/gx_internal.h @@ -101,6 +101,10 @@ extern float g_projectionVector[7]; struct TexObjMeta : GxTextureBindingContract::SamplerState { uint32_t userData = 0; bool needsUpload = true; + // GXInitTexObj/GXInitTexObjCI ran since the last load: the aurora object is + // rebuilt from scratch on the next load, as it always was, so its data + // version restarts and aurora's upload cache keys repeat across frames. + bool reinitPending = false; }; // --- Host-side texture object storage (audit F9) --- @@ -384,6 +388,7 @@ struct GxTexObjLoad { uint32_t objAddr = 0; uint32_t tid = 0; bool upload = false; + bool reinit = false; }; void GxHostLoadTexObj_gx(GxTexObjLoad load); void GxHostBindPlaceholder_gx(uint32_t tid); diff --git a/runtime/src/hle/gx/gx_texture.cpp b/runtime/src/hle/gx/gx_texture.cpp index 179ed47..65b65bd 100644 --- a/runtime/src/hle/gx/gx_texture.cpp +++ b/runtime/src/hle/gx/gx_texture.cpp @@ -251,7 +251,7 @@ extern "C" void GX__InitTexObj_801707f8(uint32_t oa, uint32_t da, uint32_t w, ui } const uint32_t canonicalDataAddr = CanonicalizeGxMainRamAddress(da); std::lock_guard guard(g_texObjMutex); TexObjMeta& meta = GetTexObjMeta(oa); - meta.dataAddr=canonicalDataAddr; meta.width=(u16)w; meta.height=(u16)h; meta.format=f; meta.wrapS=ws; meta.wrapT=wt; meta.mipmap=(m!=0); meta.userData=0; meta.needsUpload=true; + meta.dataAddr=canonicalDataAddr; meta.width=(u16)w; meta.height=(u16)h; meta.format=f; meta.wrapS=ws; meta.wrapT=wt; meta.mipmap=(m!=0); meta.userData=0; meta.needsUpload=true; meta.reinitPending=true; // Also write to guest memory so reads work WriteGuestTexObj(oa, canonicalDataAddr, (u16)w, (u16)h, f, ws, wt, m != 0, false, 0); } @@ -291,7 +291,7 @@ extern "C" void GX__InitTexObjCI_80170a04(uint32_t oa, uint32_t da, uint32_t w, } const uint32_t canonicalDataAddr = CanonicalizeGxMainRamAddress(da); std::lock_guard guard(g_texObjMutex); TexObjMeta& meta = GetTexObjMeta(oa); - meta.dataAddr=canonicalDataAddr; meta.width=(u16)w; meta.height=(u16)h; meta.format=f; meta.wrapS=ws; meta.wrapT=wt; meta.mipmap=(m!=0); meta.tlut=tl; meta.userData=0; meta.needsUpload=true; + meta.dataAddr=canonicalDataAddr; meta.width=(u16)w; meta.height=(u16)h; meta.format=f; meta.wrapS=ws; meta.wrapT=wt; meta.mipmap=(m!=0); meta.tlut=tl; meta.userData=0; meta.needsUpload=true; meta.reinitPending=true; // Also write to guest memory so reads work WriteGuestTexObj(oa, canonicalDataAddr, (u16)w, (u16)h, f, ws, wt, m != 0, true, tl); // GXInitTexObjCI clears bit1 in the flags byte; keep guest memory consistent. @@ -528,7 +528,9 @@ extern "C" void GX__LoadTexObj_80170f2c(uint32_t oa, uint32_t tid) { load.objAddr = oa; load.tid = tid; load.upload = meta.needsUpload; + load.reinit = meta.reinitPending; meta.needsUpload = false; + meta.reinitPending = false; load.meta = meta; // Write through GetTexObjMeta so the DCStoreRange interval index is // told this entry's backing may have moved. @@ -627,7 +629,10 @@ void GxHostLoadTexObj_gx(GxTexObjLoad load) { const uint32_t size = GXGetTexBufferSize(meta.width, meta.height, meta.format, (GXBool)meta.mipmap, maxLod); GxHostTexObjEntry& entry = g_gxHostTexObjs[oa]; GXTexObj* obj = entry.host.constructed ? entry.host.PublicPtr() : nullptr; - const bool needsInit = obj == nullptr || !SameTexObjBuildMeta(entry.cached, meta); + // A guest GXInitTexObj always rebuilt the aurora object before this split; + // keeping that resets texDataVersion, so aurora's static upload cache keeps + // hitting for textures the game re-initialises every frame (menu captures). + const bool needsInit = obj == nullptr || load.reinit || !SameTexObjBuildMeta(entry.cached, meta); bool textureDataUploaded = false; try { if (needsInit) { diff --git a/runtime/src/hle/gx/gx_thread.cpp b/runtime/src/hle/gx/gx_thread.cpp index 304c12c..99f1d97 100644 --- a/runtime/src/hle/gx/gx_thread.cpp +++ b/runtime/src/hle/gx/gx_thread.cpp @@ -8,9 +8,11 @@ #include #include #include +#include #if defined(_WIN32) #include #else +#include #include #include #if defined(__linux__) @@ -30,7 +32,11 @@ constexpr uint32_t kRingBytes = 16u << 20; constexpr uint32_t kRingMask = kRingBytes - 1u; constexpr uint32_t kHeaderBytes = 16; constexpr uint32_t kFifoChunkBytes = 8192; -constexpr uint32_t kConsumerSpinIterations = 4000; +// An empty ring is usually a gap of microseconds between two bursts of the +// same frame, so the consumer spins that long before it pays a futex sleep; +// a drain likewise spins before blocking, since its backlog is normally short. +constexpr std::chrono::microseconds kConsumerSpinBudget{50}; +constexpr std::chrono::microseconds kDrainSpinBudget{300}; struct Header { uint64_t invoke; @@ -79,6 +85,66 @@ uint64_t g_statQueuePeakBytes = 0; std::atomic g_statBusyNs{0}; std::atomic g_statFaults{0}; +// Per-record-kind profile for the frame-rate log: keyed by the back function +// (or 1 for FIFO chunks, 2 for fences). Consumer-written; the producer reads +// it when it formats the log line, which is diagnostics, not synchronisation. +struct RecordProfile { + uintptr_t key = 0; + uint64_t ns = 0; + uint64_t count = 0; +}; +constexpr size_t kProfileSlots = 128; +constexpr uintptr_t kProfileKeyFifo = 1; +constexpr uintptr_t kProfileKeyFence = 2; +RecordProfile g_profile[kProfileSlots]; + +void ProfileRecord(uintptr_t key, uint64_t ns) { + size_t slot = static_cast(key >> 4) % kProfileSlots; + for (size_t probe = 0; probe < kProfileSlots; ++probe) { + RecordProfile& entry = g_profile[slot]; + if (entry.key == key || entry.key == 0) { + entry.key = key; + entry.ns += ns; + ++entry.count; + return; + } + slot = (slot + 1) % kProfileSlots; + } +} + +// Names a back function for the log: its symbol when the loader knows it, +// otherwise its offset in the module, for llvm-symbolizer on the build's .so. +std::string DescribeProfileKey(uintptr_t key) { + if (key == kProfileKeyFifo) { + return "fifo"; + } + if (key == kProfileKeyFence) { + return "fence"; + } + char buffer[96]; +#if defined(_WIN32) + HMODULE module = nullptr; + if (::GetModuleHandleExW(GET_MODULE_HANDLE_EX_FLAG_FROM_ADDRESS | GET_MODULE_HANDLE_EX_FLAG_UNCHANGED_REFCOUNT, + reinterpret_cast(key), &module) && module != nullptr) { + std::snprintf(buffer, sizeof(buffer), "+0x%llx", + static_cast(key - reinterpret_cast(module))); + return buffer; + } +#else + Dl_info info{}; + if (dladdr(reinterpret_cast(key), &info) != 0) { + if (info.dli_sname != nullptr && info.dli_saddr == reinterpret_cast(key)) { + return info.dli_sname; + } + std::snprintf(buffer, sizeof(buffer), "+0x%llx", + static_cast(key - reinterpret_cast(info.dli_fbase))); + return buffer; + } +#endif + std::snprintf(buffer, sizeof(buffer), "0x%llx", static_cast(key)); + return buffer; +} + uint64_t ElapsedNs(Clock::time_point since) { return static_cast(std::chrono::duration_cast(Clock::now() - since).count()); } @@ -128,7 +194,7 @@ void WaitWithCallback(std::condition_variable& cv, std::atomic& waitingFla } void NotifyConsumer() { - if (g_consumerSleeping.load(std::memory_order_acquire)) { + if (g_consumerSleeping.load(std::memory_order_seq_cst)) { std::lock_guard lock(g_mutex); g_cvData.notify_one(); } @@ -157,7 +223,9 @@ void PostRecordRaw(detail::Invoke invoke, const void* payload, uint32_t payloadB std::memcpy(g_ring + offset + kHeaderBytes, payload, payloadBytes); } g_localTail += stride; - g_tail.store(g_localTail, std::memory_order_release); + // seq_cst pairs with the consumer's sleeping flag: one of the two sides + // always sees the other's store, so a post never leaves the consumer asleep. + g_tail.store(g_localTail, std::memory_order_seq_cst); ++g_statRecords; g_statBytes += stride; const uint64_t queued = g_localTail - g_head.load(std::memory_order_relaxed); @@ -184,25 +252,30 @@ void ConsumerLoop() { SetThreadName(); uint64_t head = g_head.load(std::memory_order_relaxed); uint32_t spins = 0; + Clock::time_point spinStarted{}; while (true) { const uint64_t tail = g_tail.load(std::memory_order_acquire); if (head == tail) { if (g_stop.load(std::memory_order_acquire)) { break; } - if (spins < kConsumerSpinIterations) { - ++spins; + if (spins == 0) { + spinStarted = Clock::now(); + } + ++spins; + if ((spins & 31u) != 0 || Clock::now() - spinStarted < kConsumerSpinBudget) { std::this_thread::yield(); continue; } - g_consumerSleeping.store(true, std::memory_order_release); + g_consumerSleeping.store(true, std::memory_order_seq_cst); { std::unique_lock lock(g_mutex); g_cvData.wait_for(lock, std::chrono::milliseconds(1), [&] { - return g_tail.load(std::memory_order_acquire) != head || g_stop.load(std::memory_order_acquire); + return g_tail.load(std::memory_order_seq_cst) != head || g_stop.load(std::memory_order_acquire); }); } - g_consumerSleeping.store(false, std::memory_order_release); + g_consumerSleeping.store(false, std::memory_order_seq_cst); + spins = 0; continue; } spins = 0; @@ -211,6 +284,13 @@ void ConsumerLoop() { if (header.invoke != 0) { const auto started = Clock::now(); const uint8_t* payload = g_ring + ((head + kHeaderBytes) & kRingMask); + uintptr_t profileKey = kProfileKeyFifo; + if (header.invoke == reinterpret_cast(&FenceInvoke)) { + profileKey = kProfileKeyFence; + } else if (header.invoke != reinterpret_cast(&FifoInvoke)) { + // Every call record starts with the back function's pointer. + std::memcpy(&profileKey, payload, sizeof(profileKey)); + } try { reinterpret_cast(header.invoke)(payload, header.payloadBytes); } catch (const std::exception& ex) { @@ -226,7 +306,9 @@ void ConsumerLoop() { static_cast(faults)); } } - g_statBusyNs.fetch_add(ElapsedNs(started), std::memory_order_relaxed); + const uint64_t elapsed = ElapsedNs(started); + g_statBusyNs.fetch_add(elapsed, std::memory_order_relaxed); + ProfileRecord(profileKey, elapsed); } head += header.stride; g_head.store(head, std::memory_order_release); @@ -296,12 +378,15 @@ void Drain() { const uint64_t sequence = ++g_fenceRequested; PostRecordRaw(&FenceInvoke, &sequence, sizeof(sequence)); ++g_statDrains; - if (g_fenceCompleted.load(std::memory_order_acquire) >= sequence) { - return; - } const auto started = Clock::now(); - WaitWithCallback(g_cvFence, g_producerWaiting, - [&] { return g_fenceCompleted.load(std::memory_order_acquire) >= sequence; }); + while (g_fenceCompleted.load(std::memory_order_acquire) < sequence) { + if (Clock::now() - started >= kDrainSpinBudget) { + WaitWithCallback(g_cvFence, g_producerWaiting, + [&] { return g_fenceCompleted.load(std::memory_order_acquire) >= sequence; }); + break; + } + std::this_thread::yield(); + } g_statDrainWaitNs += ElapsedNs(started); } @@ -340,8 +425,8 @@ std::string FormatStatsAndReset(double windowSeconds, uint32_t frames) { const double perFrame = frames != 0 ? 1.0 / static_cast(frames) : 0.0; const double busyNs = static_cast(g_statBusyNs.exchange(0, std::memory_order_relaxed)); const double busyPercent = windowSeconds > 0.0 ? busyNs / (windowSeconds * 1e9) * 100.0 : 0.0; - char buffer[512]; - std::snprintf(buffer, sizeof(buffer), + char buffer[1024]; + const int written = std::snprintf(buffer, sizeof(buffer), "GX thread: %.0f records/frame (%.1f KiB, %.0f FIFO chunks with %.1f KiB), queue peak %.1f KiB; " "game thread waited %.2f ms/frame for ring space and %.2f ms/frame in %.1f drains/frame; " "GX thread busy %.1f%%; faults %llu", @@ -356,7 +441,19 @@ std::string FormatStatsAndReset(double windowSeconds, uint32_t frames) { static_cast(g_statFaults.load(std::memory_order_relaxed))); g_statRecords = g_statFifoRecords = g_statFifoBytes = g_statBytes = 0; g_statDrains = g_statDrainWaitNs = g_statSpaceWaitNs = g_statQueuePeakBytes = 0; - return buffer; + // The costliest record kinds of the window, as ms per frame and calls per frame. + RecordProfile top[kProfileSlots]; + std::memcpy(top, g_profile, sizeof(top)); + std::memset(g_profile, 0, sizeof(g_profile)); + std::sort(std::begin(top), std::end(top), [](const RecordProfile& a, const RecordProfile& b) { return a.ns > b.ns; }); + std::string line = written > 0 ? std::string(buffer, static_cast(std::min(written, sizeof(buffer) - 1))) : std::string(); + line += "; costliest:"; + for (size_t i = 0; i < 6 && top[i].key != 0; ++i) { + std::snprintf(buffer, sizeof(buffer), " %s %.2f ms x%.0f", DescribeProfileKey(top[i].key).c_str(), + static_cast(top[i].ns) * perFrame / 1e6, static_cast(top[i].count) * perFrame); + line += buffer; + } + return line; } namespace detail {