[PATCH 1/2] drm/i915/display: Record the plane update times for debugging

Chris Wilson chris at chris-wilson.co.uk
Wed Nov 25 17:00:14 UTC 2020


Since we try and estimate how long we require to update the registers to
perform a plane update, it is of vital importance that we measure the
distribution of plane updates to better guide our estimate. If we
underestimate how long it takes to perform the plane update, we may
slip into the next scanout frame causing a tear. If we overestimate, we
may unnecessarily delay the update to the next frame, causing visible
jitter.

Replace the warning that we exceed some arbitrary threshold for the
vblank update with a histogram for debugfs.

Closes: https://gitlab.freedesktop.org/drm/intel/-/issues/1982
Signed-off-by: Chris Wilson <chris at chris-wilson.co.uk>
Cc: Jani Nikula <jani.nikula at linux.intel.com>
Cc: Ville Syrjälä <ville.syrjala at linux.intel.com>
---
 .../drm/i915/display/intel_display_debugfs.c  | 48 +++++++++++++++++++
 .../drm/i915/display/intel_display_types.h    |  7 +++
 drivers/gpu/drm/i915/display/intel_sprite.c   | 37 ++++++++------
 drivers/gpu/drm/i915/display/intel_sprite.h   | 10 ++++
 4 files changed, 87 insertions(+), 15 deletions(-)

diff --git a/drivers/gpu/drm/i915/display/intel_display_debugfs.c b/drivers/gpu/drm/i915/display/intel_display_debugfs.c
index ca41e8c00ad7..d61fafa416b0 100644
--- a/drivers/gpu/drm/i915/display/intel_display_debugfs.c
+++ b/drivers/gpu/drm/i915/display/intel_display_debugfs.c
@@ -18,6 +18,7 @@
 #include "intel_pm.h"
 #include "intel_psr.h"
 #include "intel_sideband.h"
+#include "intel_sprite.h"
 
 static inline struct drm_i915_private *node_to_i915(struct drm_info_node *node)
 {
@@ -865,6 +866,51 @@ static void intel_scaler_info(struct seq_file *m, struct intel_crtc *crtc)
 	}
 }
 
+#ifdef CONFIG_DRM_I915_DEBUG_VBLANK_EVADE
+static void crtc_vblank_info(struct seq_file *m, struct intel_crtc *crtc)
+{
+	char buf[ARRAY_SIZE(crtc->debug.vbl_times) + 1] = {};
+	int h, row, max;
+	u64 count;
+
+	max = 0;
+	count = 0;
+	for (h = 0; h < ARRAY_SIZE(crtc->debug.vbl_times); h++) {
+		if (crtc->debug.vbl_times[h] > max)
+			max = crtc->debug.vbl_times[h];
+		count += crtc->debug.vbl_times[h];
+	}
+	seq_printf(m, "\tUpdates: %llu\n", count);
+	if (!count)
+		return;
+
+	memset(buf, '-', sizeof(buf) - 1);
+	seq_printf(m, "\t  |%s|\n", buf);
+
+	for (row = ilog2(max) - 1; row; row--) {
+		memset(buf, ' ', sizeof(buf) - 1);
+		for (h = 0; h < ARRAY_SIZE(crtc->debug.vbl_times); h++) {
+			if (ilog2(crtc->debug.vbl_times[h]) >= row)
+				buf[h] = '*';
+		}
+		seq_printf(m, "\t  |%s|\n", buf);
+	}
+
+	memset(buf, '-', sizeof(buf) - 1);
+	seq_printf(m, "\t  |%s|\n", buf);
+	seq_printf(m, "\t    1us     (log)      1ms\n");
+
+	seq_printf(m, "\tMin update: %lluns\n", crtc->debug.min_vbl_time);
+	seq_printf(m, "\tMax update: %lluns\n", crtc->debug.max_vbl_time);
+	seq_printf(m, "\tAverage update: %lluns\n",
+		   div64_u64(crtc->debug.sum_vbl_time,  count));
+	seq_printf(m, "\tOverruns > %uus: %lu\n",
+		   VBLANK_EVASION_TIME_US, crtc->debug.over_vbl_time);
+}
+#else
+static void crtc_vblank_info(struct seq_file *m, struct intel_crtc *crtc) {}
+#endif
+
 static void intel_crtc_info(struct seq_file *m, struct intel_crtc *crtc)
 {
 	struct drm_i915_private *dev_priv = node_to_i915(m->private);
@@ -907,6 +953,8 @@ static void intel_crtc_info(struct seq_file *m, struct intel_crtc *crtc)
 	seq_printf(m, "\tunderrun reporting: cpu=%s pch=%s\n",
 		   yesno(!crtc->cpu_fifo_underrun_disabled),
 		   yesno(!crtc->pch_fifo_underrun_disabled));
+
+	crtc_vblank_info(m, crtc);
 }
 
 static int i915_display_info(struct seq_file *m, void *unused)
diff --git a/drivers/gpu/drm/i915/display/intel_display_types.h b/drivers/gpu/drm/i915/display/intel_display_types.h
index ce82d654d0f2..efbb7c61e6fb 100644
--- a/drivers/gpu/drm/i915/display/intel_display_types.h
+++ b/drivers/gpu/drm/i915/display/intel_display_types.h
@@ -1186,6 +1186,13 @@ struct intel_crtc {
 		ktime_t start_vbl_time;
 		int min_vbl, max_vbl;
 		int scanline_start;
+#ifdef CONFIG_DRM_I915_DEBUG_VBLANK_EVADE
+		u64 min_vbl_time;
+		u64 max_vbl_time;
+		u64 sum_vbl_time;
+		unsigned int vbl_times[21]; /* [1us, 1ms] */
+		unsigned long over_vbl_time;
+#endif
 	} debug;
 
 	/* scalers available on this crtc */
diff --git a/drivers/gpu/drm/i915/display/intel_sprite.c b/drivers/gpu/drm/i915/display/intel_sprite.c
index 019a2d6d807a..5f6fc3b93afa 100644
--- a/drivers/gpu/drm/i915/display/intel_sprite.c
+++ b/drivers/gpu/drm/i915/display/intel_sprite.c
@@ -61,14 +61,6 @@ int intel_usecs_to_scanlines(const struct drm_display_mode *adjusted_mode,
 			    1000 * adjusted_mode->crtc_htotal);
 }
 
-/* FIXME: We should instead only take spinlocks once for the entire update
- * instead of once per mmio. */
-#if IS_ENABLED(CONFIG_PROVE_LOCKING)
-#define VBLANK_EVASION_TIME_US 250
-#else
-#define VBLANK_EVASION_TIME_US 100
-#endif
-
 /**
  * intel_pipe_update_start() - start update of a set of display registers
  * @new_crtc_state: the new crtc state
@@ -250,13 +242,28 @@ void intel_pipe_update_end(struct intel_crtc_state *new_crtc_state)
 			crtc->debug.scanline_start, scanline_end);
 	}
 #ifdef CONFIG_DRM_I915_DEBUG_VBLANK_EVADE
-	else if (ktime_us_delta(end_vbl_time, crtc->debug.start_vbl_time) >
-		 VBLANK_EVASION_TIME_US)
-		drm_warn(&dev_priv->drm,
-			 "Atomic update on pipe (%c) took %lld us, max time under evasion is %u us\n",
-			 pipe_name(pipe),
-			 ktime_us_delta(end_vbl_time, crtc->debug.start_vbl_time),
-			 VBLANK_EVASION_TIME_US);
+	{
+		unsigned int h;
+		u64 delta;
+
+		delta = ktime_to_ns(ktime_sub(end_vbl_time,
+					      crtc->debug.start_vbl_time));
+
+		h = ilog2(delta >> 9);
+		if (h >= ARRAY_SIZE(crtc->debug.vbl_times))
+			h = ARRAY_SIZE(crtc->debug.vbl_times) - 1;
+		crtc->debug.vbl_times[h]++;
+
+		crtc->debug.sum_vbl_time += delta;
+		if (!crtc->debug.min_vbl_time ||
+		    delta < crtc->debug.min_vbl_time)
+			crtc->debug.min_vbl_time = delta;
+		if (delta > crtc->debug.max_vbl_time)
+			crtc->debug.max_vbl_time = delta;
+
+		if (delta > 1000 * VBLANK_EVASION_TIME_US)
+			crtc->debug.over_vbl_time++;
+	}
 #endif
 }
 
diff --git a/drivers/gpu/drm/i915/display/intel_sprite.h b/drivers/gpu/drm/i915/display/intel_sprite.h
index cd2104ba1ca1..76126dd8d584 100644
--- a/drivers/gpu/drm/i915/display/intel_sprite.h
+++ b/drivers/gpu/drm/i915/display/intel_sprite.h
@@ -17,6 +17,16 @@ struct drm_i915_private;
 struct intel_crtc_state;
 struct intel_plane_state;
 
+/*
+ * FIXME: We should instead only take spinlocks once for the entire update
+ * instead of once per mmio.
+ */
+#if IS_ENABLED(CONFIG_PROVE_LOCKING)
+#define VBLANK_EVASION_TIME_US 250
+#else
+#define VBLANK_EVASION_TIME_US 100
+#endif
+
 int intel_usecs_to_scanlines(const struct drm_display_mode *adjusted_mode,
 			     int usecs);
 struct intel_plane *intel_sprite_plane_create(struct drm_i915_private *dev_priv,
-- 
2.20.1



More information about the Intel-gfx-trybot mailing list