megboyzz/nfsmw-online
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Cheapen the shim-call boundary: lock-free dispatch + batched register reads

Browse Source 
Every shim crossing took a std::mutex in MiscStubDispatch and five separate
uc_reg_read calls in import_stub_dispatch_cb. Measured at ~170,000 crossings
per second during gameplay, from several threads.

Dispatch table is now a fixed array plus an atomic published count. It is
append-only by construction (AllocCodeStub bump-allocates 4 bytes per stub
and refuses past the arena end), entries are never removed or rewritten, and
a writer fills its slot before publishing the count with release ordering -
so an acquiring reader always sees a complete entry. The mutex remains on
the append side, which runs a few hundred times at startup.

Register reads go through one uc_reg_read_batch instead of five API entries.

RESULT, and it is smaller than the reasoning predicted:

    time to first OnCarLoaded  36.35s -> 35.20s   (35.14 / 35.28 / 35.18)

About 3%, consistent across runs. The estimate that each crossing costs
~6us - derived by dividing a saturated core by the measured crossing rate -
implied far more headroom than this. Either the mutex and register reads
were a small part of the crossing cost, or the thread is not actually
saturated and the estimate is wrong. Recorded rather than explained away;
the change is correct and free either way, but it is not the lever the
arithmetic suggested.

Also adds temporary task #56 instrumentation, all opt-in:
- gles_shim PERF line: fps, draws/frame, shimCalls/frame in ONE line, so the
  correlation is readable live instead of joined across logs afterwards.
- guest_engine TOPSHIMS line: the busiest shims once a second, counted per
  ImportStubEntry so no shared map or mutex taxes the hot path.

Those two measurements corrected an earlier wrong conclusion. Draw calls
looked like the cause of the in-race slowdown the user demonstrated, but
with the crossing counter in place: draws/frame 178 vs 149 across a 4x fps
gap, while shimCalls/frame went 22,000 vs 5,600 - and fps falls out exactly
as crossings-per-second / crossings-per-frame (148350/4385 = 33.8,
167811/21665 = 7.7). Draws were a bystander.

Co-Authored-By: Claude <noreply@anthropic.com>
This commit is contained in:
megboyzz
2026-09-19 19:33:53 +03:00
co-authored by Claude
parent 1a74432c48
commit 9c4a455bb0
3 changed files with 193 additions and 21 deletions
Download Patch File Download Diff File Expand all files Collapse all files
mpcore/src/main/cpp/emu/gles_shim.cpp
+77 -2
View File
@@ -14,6 +14,12 @@
#include <EGL/egl.h>
#include <android/bitmap.h>
// Defined in guest_engine.cpp at global scope - counts EVERY shim crossing
// (libc, JNI, GLES), which is what the PERF line needs to answer whether our
// shim boundary is what paces the frame. Declared here rather than in a
// header because it is temporary task #56 instrumentation.
extern std::atomic<uint64_t> g_stubDispatchCount;
// 2026-09-18 (task #39): needs real external linkage, unlike everything else
// in this file's anonymous namespace below, because guest_engine.cpp's
// TextClipDispatchEntryProbeHookCb reads it via `extern` from a different
@@ -91,6 +97,61 @@ void NoteDrawForSwapGate() {
}
}
// Task #56 live metrics (2026-09-19, temporary - flip off when the session
// ends). The user's observation is the whole reason this exists: after
// crashing into a wall with nothing ahead the game runs fast, and the moment
// objects or particles (motion blur, nitro, collision sparks) appear the
// speed drops at once. That points at per-DRAW cost on our side rather than
// at physics, race logic, or the GPU - the in-race profile had the Mali
// driver at only 1.3%.
//
// So: report draw calls and frames once a second, together, in ONE line, so
// the correlation can be read live while driving instead of joining two logs
// by timestamp afterwards. Frames are counted as synthesized-frame
// boundaries would be - here, default-framebuffer draws reset per swap - so
// drawsPerFrame is the number that matters.
constexpr bool kLogPerfMetrics = true;
std::atomic<uint64_t> g_totalDraws{0};
std::atomic<uint64_t> g_totalIndices{0};
std::atomic<uint64_t> g_framesSeen{0};
void NotePerfDraw(GLsizei count) {
if (!kLogPerfMetrics) return;
g_totalDraws.fetch_add(1, std::memory_order_relaxed);
g_totalIndices.fetch_add((uint64_t)(count > 0 ? count : 0), std::memory_order_relaxed);
static std::atomic<uint64_t> lastNs{0};
uint64_t now = (uint64_t)std::chrono::duration_cast<std::chrono::nanoseconds>(
std::chrono::steady_clock::now().time_since_epoch()).count();
uint64_t last = lastNs.load(std::memory_order_relaxed);
if (now - last < 1000000000ull) return;
if (!lastNs.compare_exchange_strong(last, now, std::memory_order_relaxed)) return;
if (last == 0) return;
static uint64_t prevDraws = 0, prevIdx = 0, prevFrames = 0, prevGl = 0;
double dt = (now - last) / 1e9;
uint64_t d = g_totalDraws.load(std::memory_order_relaxed);
uint64_t ix = g_totalIndices.load(std::memory_order_relaxed);
uint64_t f = g_framesSeen.load(std::memory_order_relaxed);
double frames = (double)(f - prevFrames) / dt;
double draws = (double)(d - prevDraws) / dt;
// glCalls distinguishes the two candidate explanations for the drop the
// user demonstrated (task #56). If GLES shim calls per FRAME rise along
// with draws, the cost is on our side of the boundary - more state
// changes, each one a shim crossing. If calls per frame stay flat while
// fps collapses, our boundary is not what is pacing the frame, and the
// next suspect is the GPU: particles are blended overdraw, and a CPU
// profile cannot see a thread that is BLOCKED rather than busy (the
// lesson task #49 already charged us for once).
uint64_t gl = g_stubDispatchCount.load(std::memory_order_relaxed);
Log("gles_shim: PERF fps=%.1f draws/s=%.0f draws/frame=%.0f indices/draw=%.0f "
"shimCalls/s=%.0f shimCalls/frame=%.0f shimCalls/draw=%.1f",
frames, draws, frames > 0 ? draws / frames : 0.0,
(d - prevDraws) ? (double)(ix - prevIdx) / (double)(d - prevDraws) : 0.0,
(double)(gl - prevGl) / dt, frames > 0 ? (double)(gl - prevGl) / dt / frames : 0.0,
(d - prevDraws) ? (double)(gl - prevGl) / (double)(d - prevDraws) : 0.0);
prevGl = gl;
prevDraws = d; prevIdx = ix; prevFrames = f;
}
std::atomic<int> g_textUploadTraceWindow{0};
bool LooksLikeTextOverlayUpload(GLsizei width, GLsizei height) {
// 738x302 specifically, plus a little slack for other similarly-shaped
@@ -538,11 +599,23 @@ uint32_t Shim_glClear(GuestEngine& eng, uint32_t r0, uint32_t r1, uint32_t r2, u
// is found - that symptom was diagnosed under the false premise above and
// its actual explanation is therefore still open.
constexpr bool kSynthesizeSwap = false;
const bool frameBoundary =
kSynthesizeSwap &&
// The boundary CONDITION is still worth evaluating even though we no
// longer present on it (task #47): it is the only per-frame signal this
// shim has natively, and task #56 needs draws-per-FRAME, not draws per
// second. Counting here also restores the g_drawsSinceSwap reset that the
// disabled swap block used to perform - without it "drew into screen"
// would latch true after the first draw and every later FBO clear would
// be counted as a frame.
const bool rawFrameBoundary =
((boundFb != 0 && drewIntoScreen) ||
(boundFb == 0 && clearsColor && drewIntoScreen &&
!sawFboClear.load(std::memory_order_relaxed)));
if (rawFrameBoundary && kLogPerfMetrics && !kSynthesizeSwap) {
if (g_drawsSinceSwap.exchange(0, std::memory_order_relaxed) > 0) {
g_framesSeen.fetch_add(1, std::memory_order_relaxed);
}
}
const bool frameBoundary = kSynthesizeSwap && rawFrameBoundary;
if (frameBoundary) {
static std::atomic<bool> hasClearedBefore{false};
// 2026-09-19: also require that SOMETHING was actually drawn into the
@@ -814,6 +887,7 @@ uint32_t Shim_glDrawArrays(GuestEngine& eng, uint32_t r0, uint32_t r1, uint32_t
glDrawArrays((GLenum)eng.ReadIncomingArg(0, r0, r1, r2, r3, sp), (GLint)eng.ReadIncomingArg(1, r0, r1, r2, r3, sp), count);
g_drawArraysCalls.fetch_add(1, std::memory_order_relaxed);
g_drawArraysVerts.fetch_add((uint64_t)(count > 0 ? count : 0), std::memory_order_relaxed);
NotePerfDraw(count);
NoteDrawForSwapGate();
return 0;
}
@@ -986,6 +1060,7 @@ uint32_t Shim_glDrawElements(GuestEngine& eng, uint32_t r0, uint32_t r1, uint32_
: (a3_g ? eng.G2H(a3_g) : nullptr);
glDrawElements((GLenum)eng.ReadIncomingArg(0, r0, r1, r2, r3, sp), count, (GLenum)eng.ReadIncomingArg(2, r0, r1, r2, r3, sp), indicesArg);
g_drawElementsCalls.fetch_add(1, std::memory_order_relaxed);
NotePerfDraw(count);
NoteDrawForSwapGate();
g_drawElementsIndices.fetch_add((uint64_t)(count > 0 ? count : 0), std::memory_order_relaxed);
{
mpcore/src/main/cpp/emu/guest_engine.cpp
+101 -17
View File
@@ -133,7 +133,7 @@ constexpr uint32_t kGuardPageSize = kPageSize;
// TCG to re-translate (tb_invalidate_phys_page_fast_arm, 3.15%). If this
// reports zero, the invalidation comes from somewhere else and that lead
// is dead.
constexpr bool kCountStubDispatches = false;
constexpr bool kCountStubDispatches = true;
constexpr bool kCountTextWrites = false;
// kCountArenaWrites - task #54. tb_invalidate_phys_page_fast_arm is 5.56% of
// the in-race profile and its cause is open: the .text write counter above
@@ -187,8 +187,26 @@ struct ImportStubEntry {
std::string name;
ImportShimFn shim; // nullptr if not implemented - see guest_engine's own unresolved-import log-once behavior
bool loggedUnresolved = false;
// Task #56 instrumentation (2026-09-19, temporary). Live measurement on
// the Xiaomi 14 showed shim crossings/sec pinned near a ceiling (~170k)
// regardless of scene, with the frame rate falling out as
// ceiling / crossings-per-frame - 148350/4385 = 33.8fps fast,
// 167811/21665 = 7.7fps slow, both exact. Draw calls turned out NOT to
// be the driver (178 vs 149 per frame across a 4x fps gap). So the
// question is WHICH shims make up that flood. Counted per entry rather
// than in a shared map because a mutex on every crossing would tax the
// very thing being measured.
std::atomic<uint64_t> calls{0};
uint64_t prevCalls = 0;
};
// All entries ever created, for the per-second top-N report. Appended under
// the mutex at creation time (rare); read without one by the reporter, which
// is safe because entries are never destroyed and the vector only grows
// during startup.
std::mutex g_importStubEntriesMutex;
std::vector<ImportStubEntry*> g_importStubEntries;
// Diagnostic only (see ARM64_TRANSLATION_LAYER.md's "why does the process
// die" investigation) - fires on every UC_ERR_READ/WRITE/FETCH_UNMAPPED
// fault AND every _PROT violation (registered as UC_HOOK_MEM_INVALID, not
@@ -2215,14 +2233,60 @@ void RenderCrashProbeHookCb(uc_engine* uc, uint64_t, uint32_t, void*) {
// executes the real `BX LR` immediately after, still inside the *same*
// uc_emu_start() call, using LR exactly as it already stands (untouched by
// this function) for correct ARM/Thumb interworking.
// Prints the busiest shims once a second. Time-gated with a CAS so only one
// thread does the work; everything else just returns after its increment.
void ReportTopShims() {
static std::atomic<uint64_t> lastNs{0};
uint64_t now = (uint64_t)std::chrono::duration_cast<std::chrono::nanoseconds>(
std::chrono::steady_clock::now().time_since_epoch()).count();
uint64_t last = lastNs.load(std::memory_order_relaxed);
if (now - last < 1000000000ull) return;
if (!lastNs.compare_exchange_strong(last, now, std::memory_order_relaxed)) return;
if (last == 0) return;
double dt = (now - last) / 1e9;
std::vector<std::pair<uint64_t, ImportStubEntry*>> hot;
uint64_t total = 0;
{
std::lock_guard<std::mutex> lock(g_importStubEntriesMutex);
for (auto* e : g_importStubEntries) {
uint64_t c = e->calls.load(std::memory_order_relaxed);
uint64_t delta = c - e->prevCalls;
e->prevCalls = c;
total += delta;
if (delta) hot.emplace_back(delta, e);
}
}
if (hot.empty()) return;
std::sort(hot.begin(), hot.end(), [](auto& a, auto& b) { return a.first > b.first; });
std::string s;
for (size_t i = 0; i < hot.size() && i < 8; i++) {
char buf[128];
snprintf(buf, sizeof(buf), " %s=%.0f/s(%.0f%%)", hot[i].second->name.c_str(),
(double)hot[i].first / dt, 100.0 * (double)hot[i].first / (double)total);
s += buf;
}
Log("GuestEngine: TOPSHIMS total=%.0f/s over %zu distinct |%s", (double)total / dt, hot.size(),
s.c_str());
}
void import_stub_dispatch_cb(uc_engine* uc, uint64_t address, uint32_t /*size*/, void* user_data) {
auto* entry = static_cast<ImportStubEntry*>(user_data);
if (kCountStubDispatches) {
entry->calls.fetch_add(1, std::memory_order_relaxed);
ReportTopShims();
}
// One batched read instead of five separate uc_reg_read calls (task #56).
// Each uc_reg_read is a full Unicorn API entry - argument checks plus a
// per-arch switch - and this runs on EVERY shim crossing, measured at
// ~170,000/sec during gameplay. uc_reg_read_batch does the same work
// behind a single entry.
uint32_t r0 = 0, r1 = 0, r2 = 0, r3 = 0, sp = 0;
uc_reg_read(uc, UC_ARM_REG_R0, &r0);
uc_reg_read(uc, UC_ARM_REG_R1, &r1);
uc_reg_read(uc, UC_ARM_REG_R2, &r2);
uc_reg_read(uc, UC_ARM_REG_R3, &r3);
uc_reg_read(uc, UC_ARM_REG_SP, &sp);
{
static const int kRegs[5] = {UC_ARM_REG_R0, UC_ARM_REG_R1, UC_ARM_REG_R2,
UC_ARM_REG_R3, UC_ARM_REG_SP};
void* vals[5] = {&r0, &r1, &r2, &r3, &sp};
uc_reg_read_batch(uc, kRegs, vals, 5);
}
uint32_t result = 0;
if (entry->shim) {
@@ -2863,6 +2927,10 @@ GuestAddr GuestEngine::ResolveOrCreateImportStub(const std::string& symbolName)
auto* entry = new ImportStubEntry();
entry->name = symbolName;
{
std::lock_guard<std::mutex> lock(g_importStubEntriesMutex);
g_importStubEntries.push_back(entry);
}
auto shimIt = registered_shims_.find(symbolName);
entry->shim = (shimIt != registered_shims_.end()) ? shimIt->second : nullptr;
@@ -3350,7 +3418,15 @@ GuestAddr GuestEngine::CarveThreadStack() {
return base + kStackSize; // top = highest usable address, same convention the old stack_top_ used
}
// Task #56: every shim crossing (libc, JNI and GLES alike) passes through
// here, so one relaxed increment gives a total that gles_shim's PERF line can
// print alongside fps and draws in a SINGLE log line - which is the whole
// point, since the question is whether shim calls per FRAME rise when the
// frame rate collapses. At ~50-90k dispatches/sec a relaxed add is noise.
std::atomic<uint64_t> g_stubDispatchCount{0};
void GuestEngine::MiscStubDispatch(uc_engine* uc, uint64_t address, uint32_t size, void* /*userData*/) {
g_stubDispatchCount.fetch_add(1, std::memory_order_relaxed);
auto& eng = GuestEngine::Instance();
// Task #48 follow-up measurement (2026-09-19, temporary). The in-race
// profile puts 41.66% of CPU in helper_uc_tracecode but only 0.04% in
@@ -3380,16 +3456,16 @@ void GuestEngine::MiscStubDispatch(uc_engine* uc, uint64_t address, uint32_t siz
}
if (address < eng.misc_stub_arena_start_) return; // shouldn't happen - registered range starts here
size_t idx = (address - eng.misc_stub_arena_start_) / 4;
GuestEngine::MiscStubEntry entry;
{
std::lock_guard<std::mutex> lock(eng.misc_stub_dispatch_table_mutex_);
if (idx >= eng.misc_stub_dispatch_table_.size()) {
Log("GuestEngine::MiscStubDispatch: address 0x%llx -> index %zu out of range (table size %zu)",
(unsigned long long)address, idx, eng.misc_stub_dispatch_table_.size());
return;
}
entry = eng.misc_stub_dispatch_table_[idx];
// No lock here - see misc_stub_dispatch_table_'s own comment. Acquiring
// the published count pairs with the release store in AllocCodeStub, so
// any entry within `count` is fully written.
size_t count = eng.misc_stub_dispatch_count_.load(std::memory_order_acquire);
if (idx >= count) {
Log("GuestEngine::MiscStubDispatch: address 0x%llx -> index %zu out of range (table size %zu)",
(unsigned long long)address, idx, count);
return;
}
const GuestEngine::MiscStubEntry& entry = eng.misc_stub_dispatch_table_[idx];
entry.callback(uc, address, size, entry.userData);
}
@@ -3435,7 +3511,15 @@ GuestAddr GuestEngine::AllocCodeStub(uc_cb_hookcode_t callback, void* userData)
// since this is a pure sequential 4-byte bump allocator with no frees.
{
std::lock_guard<std::mutex> lock(misc_stub_dispatch_table_mutex_);
misc_stub_dispatch_table_.push_back({callback, userData});
size_t n = misc_stub_dispatch_count_.load(std::memory_order_relaxed);
if (n >= kMaxMiscStubs) {
Log("GuestEngine::AllocCodeStub: dispatch table full (%zu entries) - stub arena and "
"table are sized together, so this means kMiscStubArenaSize grew without "
"kMaxMiscStubs following it", n);
return 0;
}
misc_stub_dispatch_table_[n] = {callback, userData};
misc_stub_dispatch_count_.store(n + 1, std::memory_order_release);
}
// Callers store this as a guest-visible, indirectly-callable code
// pointer (GOT/PLT relocation targets, guest JNIEnv function-table
@@ -3550,7 +3634,7 @@ uint32_t GuestEngine::CallGuestFunction(GuestAddr target, const uint32_t* args,
if (plainTarget >= misc_stub_arena_start_ && plainTarget < misc_stub_end_) {
size_t idx = (plainTarget - misc_stub_arena_start_) / 4;
std::lock_guard<std::mutex> lk(misc_stub_dispatch_table_mutex_);
if (idx < misc_stub_dispatch_table_.size()) {
if (idx < misc_stub_dispatch_count_.load(std::memory_order_acquire)) {
const MiscStubEntry& e = misc_stub_dispatch_table_[idx];
if (e.callback == import_stub_dispatch_cb) {
stubKind = "import stub";
mpcore/src/main/cpp/emu/guest_engine.h
+15 -2
View File
@@ -551,8 +551,21 @@ private:
uc_cb_hookcode_t callback;
void* userData;
};
std::vector<MiscStubEntry> misc_stub_dispatch_table_;
std::mutex misc_stub_dispatch_table_mutex_;
// Lock-free on the read side (2026-09-19, task #56). This table is hit on
// EVERY shim crossing - measured at ~170,000/sec during gameplay on the
// Xiaomi 14, from several threads - and taking a std::mutex there taxed
// the exact thing being measured. A fixed array plus an atomic published
// count removes it safely: the arena is only kMiscStubArenaSize/4 stubs
// wide by construction (AllocCodeStub bump-allocates 4 bytes each and
// refuses past the end), entries are appended and never removed or
// rewritten, and a writer fills its slot BEFORE publishing the new count
// with release ordering. A reader that acquires the count therefore sees
// a fully-written entry. The mutex stays for the append side, which runs
// a few hundred times at startup.
static constexpr size_t kMaxMiscStubs = 16 * 1024 / 4;
MiscStubEntry misc_stub_dispatch_table_[kMaxMiscStubs] = {};
std::atomic<size_t> misc_stub_dispatch_count_{0};
std::mutex misc_stub_dispatch_table_mutex_; // append side only
// See crashed()'s own comment. Global (not per-thread) on purpose - a
// fault on ANY thread means the ONE shared host_region_ every thread's