wip: framegen cadence compositor debug

app/src/main/cpp/waylandcomp/src/compositor.c

@@ -898,7 +898,10 @@ static void take_dmabuf(struct surface *s, struct dmabuf_buffer *b, struct wl_re
      * the display layer draws on screen while the counter sat at 0.0 fps and 1000.0 ms. */
     if (s == g_hud_surface) {
         g_hud_alive_ns = now_ns();
-        if (!repeat) { g_hud_last_ns = g_hud_alive_ns; g_hud_fresh = 1; droiddeck_on_game_frame(); }
+        if (!repeat) { g_hud_last_ns = g_hud_alive_ns; g_hud_fresh = 1; droiddeck_on_game_frame();
+            droiddeck_log("dd-source", "recv=%lld tick=%lld buffer=%u", (long long)g_hud_last_ns,
+                          (long long)g_tick_vsync_ns, wl_resource_get_id(buffer));
+        }
     }
 }
 
@@ -2337,6 +2340,7 @@ static void on_vsync(int64_t frame_time_ns) {
     }
     g_last_vsync_ns = now;
     g_tick_vsync_ns = frame_time_ns;
+    droiddeck_log("dd-vtick", "frame=%lld dispatch=%lld", (long long)frame_time_ns, (long long)now);
     /* The app's surface may have been replaced or taken away since the last frame: apply that now
      * (the app never waits for us), and redraw the scene onto a new one. */
     if (vkp_apply_window_request()) g_dirty = 1;

tools/gamescope/patches/0115-debug-frame-cadence.patch

@@ -0,0 +1,44 @@
+--- a/src/steamcompmgr.cpp
++++ b/src/steamcompmgr.cpp
+@@ -7979,6 +7979,18 @@
+ 		{
+ 			gpuvis_trace_printf( "commit %lu done", w->commit_queue[ j ]->commitID );
+ 			w->commit_queue[ j ]->done = true;
++            if (w->appID == 1794680) {
++        static uint64_t last=0, start=0; static unsigned h[12]={};
++        const uint64_t now=get_time_in_nanos();
++        if (last) h[std::min<uint64_t>((now-last)/4000000,11)]++;
++        last=now; if (!start) start=now;
++        if (now-start>=10000000000ULL) {
++            fprintf(stderr,"[dd-latch] span=%lu bins4ms:",now-start);
++            for (unsigned value:h) fprintf(stderr," %u",value);
++            fprintf(stderr,"\n"); memset(h,0,sizeof(h)); start=now;
++        }
++
++            }
+ 			w->commit_queue[ j ]->earliest_present_time = earliestPresentTime;
+ 			w->commit_queue[ j ]->present_margin = earliestPresentTime - earliestLatchTime;
+ 			bFoundWindow = true;
+--- a/src/Backends/WaylandBackend.cpp
++++ b/src/Backends/WaylandBackend.cpp
+@@ -1473,6 +1473,20 @@
+ 
+     void CWaylandPlane::Present( std::optional<WaylandPlaneState> oState )
+     {
++        static wl_buffer *lastBuffer=nullptr;
++        if (oState && oState->bOpaque && oState->flSrcWidth>1 && oState->pBuffer!=lastBuffer) {
++            lastBuffer=oState->pBuffer;
++        static uint64_t last=0, start=0; static unsigned h[12]={};
++        const uint64_t now=get_time_in_nanos();
++        if (last) h[std::min<uint64_t>((now-last)/4000000,11)]++;
++        last=now; if (!start) start=now;
++        if (now-start>=10000000000ULL) {
++            fprintf(stderr,"[dd-plane-cadence] span=%lu bins4ms:",now-start);
++            for (unsigned value:h) fprintf(stderr," %u",value);
++            fprintf(stderr,"\n"); memset(h,0,sizeof(h)); start=now;
++        }
++
++        }
+         {
+             std::unique_lock lock( m_PlaneStateLock );
+             m_oCurrentPlaneState = oState;

tools/gamescope/patches/0115-vblank-timer-once-per-refresh.patch

@@ -0,0 +1,36 @@
+--- a/src/vblankmanager.cpp
++++ b/src/vblankmanager.cpp
+@@ -89,7 +89,12 @@
+ 
+ 		uint64_t ulTargetPoint = GetLastVBlank() + ulIntervalNSecs - ulOffset;
+ 
+-		while ( ulTargetPoint < ulNow )
++		// Host feedback can re-arm us after we already woke for this refresh.
++		// A decaying draw offset then puts the same refresh's wakeup ahead of
++		// now again. Do not count it twice; allow small host-clock corrections.
++		const uint64_t ulLastTimerVBlank = m_ulLastTimerVBlank.load();
++		while ( ulTargetPoint < ulNow ||
++		        ulTargetPoint + ulOffset < ulLastTimerVBlank + ulIntervalNSecs / 2 )
+ 			ulTargetPoint += ulIntervalNSecs;
+ 
+ 		return ulTargetPoint;
+@@ -299,6 +304,8 @@
+ 				return;
+ 
+ 
++			m_ulLastTimerVBlank = m_TimerFDSchedule.ulTargetVBlank;
++
+ 			m_PendingVBlank = VBlankTime
+ 			{
+ 				.schedule = m_TimerFDSchedule,
+--- a/src/vblankmanager.hpp
++++ b/src/vblankmanager.hpp
+@@ -69,6 +69,8 @@
+ 
+         uint64_t m_ulTargetVBlank = 0;
+         std::atomic<uint64_t> m_ulLastVBlank = { 0 };
++        // Last timerfd refresh dispatched; the frame-sync/nudge path is unchanged.
++        std::atomic<uint64_t> m_ulLastTimerVBlank = { 0 };
+         std::atomic<bool> m_bArmed = { false };
+         std::atomic<bool> m_bRunning = { true };
+ 

tools/gamescope/patches/0116-wayland-host-draw-margin.patch

@@ -0,0 +1,16 @@
+--- a/src/Backends/WaylandBackend.cpp
++++ b/src/Backends/WaylandBackend.cpp
+@@ -1183,7 +1183,12 @@
+         wl_display_flush( m_pBackend->GetDisplay() );
+ 
+         GetVBlankTimer().UpdateWasCompositing( bNeedsFullComposite );
+-        GetVBlankTimer().UpdateLastDrawTime( get_time_in_nanos() - g_SteamCompMgrVBlankTime.ulWakeupTime );
++        // Direct planes still need time for the host compositor to dispatch and draw.
++        // Measuring only our submission lets the offset decay towards the host's
++        // latch deadline, so small dispatch delays make a capped frame miss a refresh.
++        GetVBlankTimer().UpdateLastDrawTime( std::max<uint64_t>(
++            get_time_in_nanos() - g_SteamCompMgrVBlankTime.ulWakeupTime,
++            CVBlankTimer::kDefaultVBlankDrawTimeMinCompositing ) );
+ 
+         m_pBackend->PollState();
+