Transport: MOBILEGL_IPC_WAIT_STATS logs the run-ahead client's waits per frame by record op, quiesce reason and barriered verb; the per-frame P65ClientPace line drops to debug.

MobileGL/Config.h

@@ -708,6 +708,10 @@ namespace MobileGL::MG_Config {
         // client that is already CPU-bound and costs a frame of latency, which is why the
         // default is 1 and not "as deep as the ring".
         Uint32 PresentCredit = 1;
+        // MOBILEGL_IPC_WAIT_STATS (P15, diagnostic): every 600 presents, log how many times per
+        // frame the run-ahead client waited, by record op (applied/reply), by quiesce reason and
+        // barriered verb, for ring space and for the present credit. Off by default.
+        Bool WaitStats = false;
         // MOBILEGL_IPC_CONTROL_TIMEOUT_MS (CONTRACT-P6 §5.4 D5b): how long a spawn/tcp client
         // waits for the SurfaceReply to one surface-control op (eglCreate*Surface, MakeCurrent,
         // ...) once the server's backend is up. Its expiry is NOT fatal: the doorbell's death

MobileGL/ConfigLoader.cpp

@@ -617,6 +617,7 @@ namespace MobileGL::MG_ConfigLoader {
         ipc.ControlTimeoutMs = QueryEnvUint32("MOBILEGL_IPC_CONTROL_TIMEOUT_MS", 5000, 100, 600000);
         ipc.ColdStartMs = QueryEnvUint32("MOBILEGL_IPC_COLD_START_MS", 20000, 100, 600000);
         ipc.StrictErrors = QueryEnvFlag("MOBILEGL_IPC_STRICT_ERRORS");
+        ipc.WaitStats = QueryEnvFlag("MOBILEGL_IPC_WAIT_STATS");
         ipc.Audit = QueryEnvFlag("MOBILEGL_IPC_AUDIT");
         QueryEnvVariable("MOBILEGL_IPC_SERVER_AFFINITY", ipc.ServerAffinity, "auto");
         // P5f f1: the dual-block rehearsal (P5F-WIRE-COMPLETENESS.md §4). Forced OFF by the

MobileGL/MG_Impl/Pipe/PipeFill.cpp

@@ -3463,6 +3463,7 @@ namespace MobileGL::MG_Pipe {
             // delete it and the guard below aborts with Fatal{RoleViolation, "gPipeInputs"}
             // naming MGPipeValidateForVerb, because the guard now tests the fact rather than
             // taking the claim.
+            if (runAhead) MG_Remote::Client::ClientSession::NoteBarrieredVerbForStats(kMGPipeVerbNames[static_cast<SizeT>(verb)]);
             QuiesceApplierBeforeFill("MGPipeValidateForVerb");
             MG_Remote::Client::ClientSession::RefusePipeInputsTouchWhileApplierOwnsIt(
                 "MGPipeValidateForVerb", /*isBarrieredFill=*/barriered);

MobileGL/MG_Remote/Client/ClientSession.cpp

@@ -24,6 +24,7 @@
 #include "../Transport/FdPassing.h"
 #include "../Transport/InProcessTransport.h"
 #include "WireTables.h"
+#include "../Wire/PipeWireCodec.h"
 #include "EmitTables.h"
 #include <MG_State/GLState/BufferState/PersistentMapTracker.h>
 #include "ServerProbe.h"
@@ -270,6 +271,53 @@ namespace MobileGL::MG_Remote::Client {
             BarrierWaitScope& operator=(const BarrierWaitScope&) = delete;
         };
 
+        // P15: THE WAIT CENSUS (MOBILEGL_IPC_WAIT_STATS=1). Run-ahead records and replays
+        // asynchronously by default, so in steady state the only per-frame wait should be the
+        // present credit; this counts every other one so a sync point cannot hide. GL-thread
+        // only (the client's waits all happen there), so plain counters.
+        struct WaitCensus {
+            static constexpr SizeT kReasons = 32;
+            Array<Uint32, static_cast<SizeT>(MG_Pipe::MGPWireOp::kOpCount)> recordWaits{};
+            Array<const char*, kReasons> reasonNames{};
+            Array<Uint32, kReasons> reasonCounts{};
+            Uint32 ringSpace = 0;
+            Uint32 presentCredit = 0;
+            Uint32 frames = 0;
+
+            void Reason(const char* why) {
+                for (SizeT i = 0; i < kReasons; ++i) {
+                    if (reasonNames[i] == nullptr) reasonNames[i] = why;
+                    if (reasonNames[i] == why || std::strcmp(reasonNames[i], why) == 0) {
+                        ++reasonCounts[i];
+                        return;
+                    }
+                }
+            }
+            void FrameEnd() {
+                if (++frames < 600) return;
+                String line;
+                char item[160];
+                const double f = static_cast<double>(frames);
+                for (SizeT i = 0; i < recordWaits.size(); ++i) {
+                    if (recordWaits[i] == 0) continue;
+                    std::snprintf(item, sizeof(item), " wait[%s]=%.2f",
+                                  Wire::WireOpName(static_cast<MG_Pipe::MGPWireOp>(i)), recordWaits[i] / f);
+                    line += item;
+                }
+                for (SizeT i = 0; i < kReasons && reasonNames[i] != nullptr; ++i) {
+                    if (reasonCounts[i] == 0) continue;
+                    std::snprintf(item, sizeof(item), " quiesce[%s]=%.2f", reasonNames[i], reasonCounts[i] / f);
+                    line += item;
+                }
+                MGLOG_I("MGPIPE-WAITS frames=%u per-frame:%s ringSpace=%.2f presentCredit=%.2f", frames,
+                        line.empty() ? " (none)" : line.c_str(), ringSpace / f, presentCredit / f);
+                recordWaits.fill(0);
+                reasonCounts.fill(0);
+                ringSpace = presentCredit = frames = 0;
+            }
+        };
+        WaitCensus g_waitCensus;
+
         // A DEADLOCK DETECTOR, NOT A PERFORMANCE GATE. The barrier exists so that a record the
         // applier never retires is reported instead of hanging: a lost record never completes at
         // all, while a slow apply completes late. The bound only has to sit far above the slowest
@@ -2187,6 +2235,7 @@ namespace MobileGL::MG_Remote::Client {
             Wire::MGPipeWireRecordLayout(op, payload, layout);
             const Uint64 toEnd = m_cmd->Capacity() - m_cmd->LocalHead() % m_cmd->Capacity();
             const Uint64 needed = layout.TotalBytes + (toEnd < layout.TotalBytes ? toEnd : 0);
+            if (MG_Config::Ipc.WaitStats) ++g_waitCensus.ringSpace;
             const BarrierWaitScope waiting;
             const auto wait = m_producer.WaitForCmdSpace(needed, kBarrierTimeoutMs);
             if (wait == Transport::SessionWait::ShutDown) {
@@ -2359,6 +2408,7 @@ namespace MobileGL::MG_Remote::Client {
             return seq;
         }
 
+        if (MG_Config::Ipc.WaitStats && RunAheadArmed()) ++g_waitCensus.recordWaits[static_cast<SizeT>(op)];
         const BarrierWaitScope waiting;
         const Uint64 waitBudgetMs = AppliedWaitBudgetMs(op, payload);
         const Transport::SessionWait wait =
@@ -2509,6 +2559,10 @@ namespace MobileGL::MG_Remote::Client {
 #endif
     }
 
+    void ClientSession::NoteBarrieredVerbForStats(const char* verb) {
+        if (MG_Config::Ipc.WaitStats) g_waitCensus.Reason(verb);
+    }
+
     void ClientSession::WaitForApplyToCatchUp(const char* why) {
 #if MOBILEGL_BUILD_DISAGGREGATED
         // A NO-OP WITHOUT RUN-AHEAD, and that is not an optimisation: under lockstep the
@@ -2517,6 +2571,7 @@ namespace MobileGL::MG_Remote::Client {
         // watermark that is already reached.
         if (!m_runAheadArmed || !m_started) return;
         if (m_producer.LastPublishedSeq() == 0) return;
+        if (MG_Config::Ipc.WaitStats) g_waitCensus.Reason(why);
         const auto deadline = std::chrono::steady_clock::now() + std::chrono::milliseconds(kBarrierTimeoutMs);
         const BarrierWaitScope waiting;
         for (;;) {
@@ -2612,6 +2667,7 @@ namespace MobileGL::MG_Remote::Client {
             // overlap and at most one frame of added latency (ruling 4 / ID-92).
             const Uint64 awaited = serial - credit;
             ++m_presentCreditWaits;
+            if (MG_Config::Ipc.WaitStats) ++g_waitCensus.presentCredit;
             // P65CLIENTPACE: WHERE THE CLIENT'S FRAME GOES, ONE LINE PER FRAME.
             //
             // The frame is a lockstep ping-pong and every stage measured so far is IDLE: the client
@@ -2652,7 +2708,9 @@ namespace MobileGL::MG_Remote::Client {
                 static_cast<double>(std::chrono::duration_cast<std::chrono::nanoseconds>(
                     std::chrono::steady_clock::now() - paceStarted).count()) / 1e6;
             const auto io = Transport::LinkMetricsTakeSendStats();
-            MGLOG_I("P65ClientPace present=%llu credit_wait_ms=%.1f | io: %llu B in %llu sendmsg "
+            // P15: MGLOG_D - an INFO line per frame on the GL thread cost a format and a
+            // logd write every present on the shipped build.
+            MGLOG_D("P65ClientPace present=%llu credit_wait_ms=%.1f | io: %llu B in %llu sendmsg "
                     "send_ms=%.1f total_ms=%.1f",
                     static_cast<unsigned long long>(serial), creditMs,
                     static_cast<unsigned long long>(io.bytes),
@@ -2661,6 +2719,7 @@ namespace MobileGL::MG_Remote::Client {
                     static_cast<double>(io.nsTotal) / 1e6);
         }
         m_presentsSent = serial;
+        if (MG_Config::Ipc.WaitStats) g_waitCensus.FrameEnd();
         return serial;
 #else
         return ++m_presentsSent;

MobileGL/MG_Remote/Client/ClientSession.h

@@ -372,6 +372,9 @@ namespace MobileGL::MG_Remote::Client {
         // in the timeout Fatal, because "which forced wait wedged" is the whole diagnostic.
         // A no-op when run-ahead is not armed (the client is already in step by construction).
         void WaitForApplyToCatchUp(const char* why);
+        // P15 wait census (MOBILEGL_IPC_WAIT_STATS): the validate point names the verb whose
+        // barriered fill is about to quiesce the applier.
+        static void NoteBarrieredVerbForStats(const char* verb);
 
         // glFinish. Flush and Finish stay no-ops ON THE WIRE (ARCHITECTURE §11, :415) - there
         // is no record to emit - but "the GL commands issued so far have completed" cannot be