Stop double-presenting every frame (task #47)

The engine synthesized an eglSwapBuffers on each detected frame boundary.
That duplicated the present Android's GLSurfaceView already performs after
every onDrawFrame return, so every frame reached the screen twice - the
second time from a buffer still holding the PREVIOUS frame.

The whole mechanism rested on a premise recorded 2026-09-18 and never
verified live: that nativeOnResume runs the guest's persistent loop on the
GLThread and never returns, leaving the framework unable to present. An
entry/exit counter added to GameRenderer.onDrawFrame shows that is false -
it returns every frame (entries=698 exits=697, the gap being the call in
flight). Rates match 1:1:

    synthetic swaps  12.98/s   (SWAPMARK, one line per swap)
    onDrawFrame      12.69/s   (so the framework swapped 12.69/s too)

The user saw this as the car jumping forward then back along its path.
Frame-by-frame the race clock stepped 1:10.06 -> 1:10.03 -> 1:10.09 ->
1:10.06, with presents arriving in pairs 10-20ms apart at a 218ms period -
exactly the synthetic swap period.

Letting the framework present is also what the real game does: libapp.so
cannot present at all (only EGL import is eglGetProcAddress; the string
"eglSwapBuffers" is absent from the binary), and on the A9 all 2,736
eglSwapBuffers calls in 46s came from Android's own framework.

Measured after, on the Pixel 6a:

    frame interval median  89ms -> 17ms
                   p90    217ms -> 19ms
                   max    316ms -> 24ms
    synthetic swaps          0 (verified, not merely absent from view)
    onDrawFrame      12.69 -> 12.39/s (throughput deliberately unchanged)

User verdict: "Сейчас очень плавно". Throughput is untouched - this fixes
presentation, not the ~7x simulation deficit.

Kept behind kSynthesizeSwap rather than deleted: the 2026-09-18 symptom it
was built for (screen cycling between stale loading screen, black, and the
real scene) was diagnosed under the false premise above, so its actual
cause is still open.

Co-Authored-By: Claude <noreply@anthropic.com>
This commit is contained in:
2026-09-19 15:25:37 +03:00
co-authored by Claude
parent f8744f0392
commit 75270898e9
2 changed files with 70 additions and 3 deletions
@@ -43,12 +43,35 @@ public class GameRenderer implements GLSurfaceView.Renderer {
this._height = i2;
}
// Task #47 instrumentation (2026-09-19, temporary). Settles a premise that
// has been reasoned from since 2026-09-18 without ever being re-verified
// live: that nativeOnResume runs the guest's persistent loop synchronously
// here and NEVER returns, so GLSurfaceView's own automatic
// post-onDrawFrame eglSwapBuffers stops firing. If that premise holds,
// this logs exactly one line reading entries=1 exits=0 and then stays
// silent forever. If the lines keep coming instead, onDrawFrame IS
// returning, the framework IS also swapping, and that is the second
// present of each observed pair.
// System.nanoTime() is CLOCK_MONOTONIC on Android - the same clock the
// native SWAPMARK lines use - so the two logs correlate directly.
private static int drawEntries = 0;
private static int drawExits = 0;
private static long lastDrawReport = 0;
@Override // android.opengl.GLSurfaceView.Renderer
public void onDrawFrame(GL10 gl10) {
drawEntries++;
long now = System.nanoTime();
if (now - lastDrawReport > 1000000000L) {
lastDrawReport = now;
android.util.Log.i("mpcore_log", "GameRenderer: onDrawFrame entries=" + drawEntries
+ " exits=" + drawExits + " t=" + now);
}
if (this.drawFrameListener != null) {
this.drawFrameListener.onDrawFrame(gl10);
} else {
this.activity.getRunLoop().onRunLoopTick();
}
drawExits++;
}
}
+47 -3
View File
@@ -502,10 +502,42 @@ uint32_t Shim_glClear(GuestEngine& eng, uint32_t r0, uint32_t r1, uint32_t r2, u
if (boundFb != 0) sawFboClear.store(true, std::memory_order_relaxed);
const bool drewIntoScreen = g_drawsSinceSwap.load(std::memory_order_relaxed) > 0;
// FIX (2026-09-19, task #47). Synthesizing a swap here is WRONG and always
// was: it duplicates the present Android's GLSurfaceView already performs
// after every onDrawFrame return, so every frame reached the screen twice.
//
// The whole mechanism rested on a premise recorded on 2026-09-18 - that
// nativeOnResume runs the guest's persistent loop synchronously on the
// GLThread and NEVER returns to onDrawFrame, leaving the framework unable
// to present. That premise was never verified live. It is false. An
// entry/exit counter in GameRenderer.onDrawFrame shows it returning every
// single frame (entries=698 exits=697 - the one gap is the call in
// progress), and the rates match 1:1:
// synthetic swaps 12.98/s (SWAPMARK, one line per swap)
// onDrawFrame 12.69/s (so the framework swaps 12.69/s too)
// = 25.67 presents/s for ~12.8 rendered frames. The measured symptom was
// presents arriving in pairs 10-20ms apart with the SECOND showing the
// PREVIOUS simulation step (race clock stepping 1:10.06 -> 1:10.03 ->
// 1:10.09 -> 1:10.06), which the user saw as the car jumping forward and
// then back along its path.
//
// Letting the framework be the only presenter is also exactly what the
// real game does: libapp.so cannot present at all - its only EGL import is
// eglGetProcAddress and the string "eglSwapBuffers" does not appear
// anywhere in the binary. On the A9 all 2,736 eglSwapBuffers calls in 46s
// came from Android's own framework code.
//
// Kept as a flag rather than deleted: if the 2026-09-18 symptom (screen
// cycling between the stale loading screen, black, and the real scene)
// ever returns, this is the first thing to flip back while the real cause
// 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 =
(boundFb != 0 && drewIntoScreen) ||
(boundFb == 0 && clearsColor && drewIntoScreen &&
!sawFboClear.load(std::memory_order_relaxed));
kSynthesizeSwap &&
((boundFb != 0 && drewIntoScreen) ||
(boundFb == 0 && clearsColor && drewIntoScreen &&
!sawFboClear.load(std::memory_order_relaxed)));
if (frameBoundary) {
static std::atomic<bool> hasClearedBefore{false};
// 2026-09-19: also require that SOMETHING was actually drawn into the
@@ -564,6 +596,18 @@ uint32_t Shim_glClear(GuestEngine& eng, uint32_t r0, uint32_t r1, uint32_t r2, u
GLfloat curClearColor[4] = {-1, -1, -1, -1};
if (sample) glGetFloatv(GL_COLOR_CLEAR_VALUE, curClearColor);
EGLBoolean ok = eglSwapBuffers(dpy, surf);
// Task #47 instrumentation (2026-09-19, temporary). One line per
// swap, not every 100th: the sampled counter said 4.59 swaps/s
// while a screen recording showed 9.03 presents/s, so the presents
// have a second source. steady_clock is CLOCK_MONOTONIC on bionic,
// matching GameRenderer's System.nanoTime(), so these timestamps
// line up with the onDrawFrame counter AND with screenrecord frame
// PTS - which is what tells us whether the extra present lands
// between our swaps or right on top of them.
Log("gles_shim: SWAPMARK n=%llu t=%lld ok=%d", (unsigned long long)n,
(long long)std::chrono::duration_cast<std::chrono::nanoseconds>(
std::chrono::steady_clock::now().time_since_epoch()).count(),
(int)ok);
if (sample) {
GLenum err = glGetError();
// 2026-09-18: also log the CURRENT glClearColor right here