From 29a649541d527021e98090f2ccd486cf21335dab Mon Sep 17 00:00:00 2001
From: Clayton Craft <clayton@craftyguy.net>
Date: Wed, 19 Mar 2025 09:47:47 -0700
Subject: [PATCH] kms.timings.presented: print debug msg when frame time is
 overflowing

Also see: #1062
---
 src/backend/kms/surface/timings.rs | 13 ++++++++++---
 1 file changed, 10 insertions(+), 3 deletions(-)

diff --git a/src/backend/kms/surface/timings.rs b/src/backend/kms/surface/timings.rs
index 28dcc9d3..98efa7bd 100644
--- a/src/backend/kms/surface/timings.rs
+++ b/src/backend/kms/surface/timings.rs
@@ -1,7 +1,7 @@
 use std::{collections::VecDeque, num::NonZeroU64, time::Duration};
 
 use smithay::utils::{Clock, Monotonic, Time};
-use tracing::error;
+use tracing::{debug, error};
 
 const FRAME_TIME_BUFFER: Duration = Duration::from_millis(1);
 const FRAME_TIME_WINDOW: usize = 3;
@@ -138,13 +138,20 @@ impl Timings {
 
     pub fn presented(&mut self, value: Time<Monotonic>) {
         if let Some(frame) = self.pending_frame.take() {
-            self.previous_frames.push_back(Frame {
+            let new_frame = Frame {
                 render_start: frame.render_start,
                 render_duration_elements: frame.render_duration_elements.unwrap_or_default(),
                 render_duration_draw: frame.render_duration_draw.unwrap_or_default(),
                 presentation_submitted: frame.presentation_submitted.unwrap(),
                 presentation_presented: value,
-            });
+            };
+            if new_frame.render_start > new_frame.presentation_submitted {
+                debug!(
+                    "frame time overflowed: {}",
+                    new_frame.frame_time().as_millis()
+                );
+            }
+            self.previous_frames.push_back(new_frame);
             while self.previous_frames.len() > Self::WINDOW_SIZE {
                 self.previous_frames.pop_front();
             }