[Intel-gfx] [PATCH] drm/i915/display: Record the plane update times for debugging

2020-11-27 Thread Chris Wilson
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 
Cc: Jani Nikula 
Cc: Ville Syrjälä 
---
 .../drm/i915/display/intel_display_debugfs.c  | 48 ++
 .../drm/i915/display/intel_display_types.h|  7 +++
 drivers/gpu/drm/i915/display/intel_sprite.c   | 50 ---
 drivers/gpu/drm/i915/display/intel_sprite.h   | 10 
 4 files changed, 98 insertions(+), 17 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..fd1a97b9e653 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)
}
 }
 
+#if IS_ENABLED(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, "\t1us (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..eef3b1fa7e92 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 long over_vbl_time;
+   unsigned int vbl_times[21]; /* [1us, 1ms] */
+#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..271bd124b98c 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 

Re: [Intel-gfx] [PATCH] drm/i915/display: Record the plane update times for debugging

2020-11-26 Thread kernel test robot
Hi Chris,

Thank you for the patch! Yet something to improve:

[auto build test ERROR on drm-intel/for-linux-next]
[also build test ERROR on drm-tip/drm-tip v5.10-rc5 next-20201126]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch]

url:
https://github.com/0day-ci/linux/commits/Chris-Wilson/drm-i915-display-Record-the-plane-update-times-for-debugging/20201127-052128
base:   git://anongit.freedesktop.org/drm-intel for-linux-next
config: i386-randconfig-a004-20201127 (attached as .config)
compiler: gcc-9 (Debian 9.3.0-15) 9.3.0
reproduce (this is a W=1 build):
# 
https://github.com/0day-ci/linux/commit/7507dad86ddaa800a17665609a0171e9b958b451
git remote add linux-review https://github.com/0day-ci/linux
git fetch --no-tags linux-review 
Chris-Wilson/drm-i915-display-Record-the-plane-update-times-for-debugging/20201127-052128
git checkout 7507dad86ddaa800a17665609a0171e9b958b451
# save the attached .config to linux build tree
make W=1 ARCH=i386 

If you fix the issue, kindly add following tag as appropriate
Reported-by: kernel test robot 

All errors (new ones prefixed by >>):

   In file included from include/drm/drm_mm.h:49,
from include/drm/drm_vma_manager.h:26,
from include/drm/drm_gem.h:40,
from drivers/gpu/drm/i915/i915_drv.h:55,
from drivers/gpu/drm/i915/display/intel_sprite.c:42:
   drivers/gpu/drm/i915/display/intel_sprite.c: In function 'dbg_vblank_evade':
   include/drm/drm_print.h:450:19: error: request for member 'dev' in something 
not a structure or union
 450 |  drm_dev_dbg((drm)->dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
 |   ^~
   drivers/gpu/drm/i915/display/intel_sprite.c:201:3: note: in expansion of 
macro 'drm_dbg_kms'
 201 |   drm_dbg_kms("Atomic update on pipe (%c) took %lld us, max time 
under evasion is %u us\n",
 |   ^~~
>> drivers/gpu/drm/i915/display/intel_display.h:96:27: error: passing argument 
>> 3 of 'drm_dev_dbg' makes pointer from integer without a cast 
>> [-Werror=int-conversion]
  96 | #define pipe_name(p) ((p) + 'A')
 |  ~^~
 |   |
 |   int
   include/drm/drm_print.h:450:38: note: in definition of macro 'drm_dbg_kms'
 450 |  drm_dev_dbg((drm)->dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
 |  ^~~
   drivers/gpu/drm/i915/display/intel_sprite.c:202:8: note: in expansion of 
macro 'pipe_name'
 202 |pipe_name(crtc->pipe),
 |^
   include/drm/drm_print.h:338:16: note: expected 'const char *' but argument 
is of type 'int'
 338 |const char *format, ...);
 |^~
   cc1: all warnings being treated as errors

vim +/drm_dev_dbg +96 drivers/gpu/drm/i915/display/intel_display.h

09a28bd9e8024d drivers/gpu/drm/i915/intel_display.h Michal Wajdeczko 2017-12-21 
 95  
09a28bd9e8024d drivers/gpu/drm/i915/intel_display.h Michal Wajdeczko 2017-12-21 
@96  #define pipe_name(p) ((p) + 'A')
09a28bd9e8024d drivers/gpu/drm/i915/intel_display.h Michal Wajdeczko 2017-12-21 
 97  

---
0-DAY CI Kernel Test Service, Intel Corporation
https://lists.01.org/hyperkitty/list/kbuild-...@lists.01.org


.config.gz
Description: application/gzip
___
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx


Re: [Intel-gfx] [PATCH] drm/i915/display: Record the plane update times for debugging

2020-11-26 Thread kernel test robot
Hi Chris,

Thank you for the patch! Perhaps something to improve:

[auto build test WARNING on drm-intel/for-linux-next]
[also build test WARNING on drm-tip/drm-tip v5.10-rc5 next-20201126]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch]

url:
https://github.com/0day-ci/linux/commits/Chris-Wilson/drm-i915-display-Record-the-plane-update-times-for-debugging/20201127-052128
base:   git://anongit.freedesktop.org/drm-intel for-linux-next
config: x86_64-allyesconfig (attached as .config)
compiler: gcc-9 (Debian 9.3.0-15) 9.3.0
reproduce (this is a W=1 build):
# 
https://github.com/0day-ci/linux/commit/7507dad86ddaa800a17665609a0171e9b958b451
git remote add linux-review https://github.com/0day-ci/linux
git fetch --no-tags linux-review 
Chris-Wilson/drm-i915-display-Record-the-plane-update-times-for-debugging/20201127-052128
git checkout 7507dad86ddaa800a17665609a0171e9b958b451
# save the attached .config to linux build tree
make W=1 ARCH=x86_64 

If you fix the issue, kindly add following tag as appropriate
Reported-by: kernel test robot 

All warnings (new ones prefixed by >>):

   In file included from include/drm/drm_mm.h:49,
from include/drm/drm_vma_manager.h:26,
from include/drm/drm_gem.h:40,
from drivers/gpu/drm/i915/i915_drv.h:55,
from drivers/gpu/drm/i915/display/intel_sprite.c:42:
   drivers/gpu/drm/i915/display/intel_sprite.c: In function 'dbg_vblank_evade':
   include/drm/drm_print.h:450:19: error: request for member 'dev' in something 
not a structure or union
 450 |  drm_dev_dbg((drm)->dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
 |   ^~
   drivers/gpu/drm/i915/display/intel_sprite.c:201:3: note: in expansion of 
macro 'drm_dbg_kms'
 201 |   drm_dbg_kms("Atomic update on pipe (%c) took %lld us, max time 
under evasion is %u us\n",
 |   ^~~
>> drivers/gpu/drm/i915/display/intel_display.h:96:27: warning: passing 
>> argument 3 of 'drm_dev_dbg' makes pointer from integer without a cast 
>> [-Wint-conversion]
  96 | #define pipe_name(p) ((p) + 'A')
 |  ~^~
 |   |
 |   int
   include/drm/drm_print.h:450:38: note: in definition of macro 'drm_dbg_kms'
 450 |  drm_dev_dbg((drm)->dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
 |  ^~~
   drivers/gpu/drm/i915/display/intel_sprite.c:202:8: note: in expansion of 
macro 'pipe_name'
 202 |pipe_name(crtc->pipe),
 |^
   include/drm/drm_print.h:338:16: note: expected 'const char *' but argument 
is of type 'int'
 338 |const char *format, ...);
 |^~

vim +/drm_dev_dbg +96 drivers/gpu/drm/i915/display/intel_display.h

09a28bd9e8024d1 drivers/gpu/drm/i915/intel_display.h Michal Wajdeczko 
2017-12-21  95  
09a28bd9e8024d1 drivers/gpu/drm/i915/intel_display.h Michal Wajdeczko 
2017-12-21 @96  #define pipe_name(p) ((p) + 'A')
09a28bd9e8024d1 drivers/gpu/drm/i915/intel_display.h Michal Wajdeczko 
2017-12-21  97  

---
0-DAY CI Kernel Test Service, Intel Corporation
https://lists.01.org/hyperkitty/list/kbuild-...@lists.01.org


.config.gz
Description: application/gzip
___
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx


[Intel-gfx] [PATCH] drm/i915/display: Record the plane update times for debugging

2020-11-26 Thread Chris Wilson
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 
Cc: Jani Nikula 
Cc: Ville Syrjälä 
---
 .../drm/i915/display/intel_display_debugfs.c  | 48 ++
 .../drm/i915/display/intel_display_types.h|  7 +++
 drivers/gpu/drm/i915/display/intel_sprite.c   | 49 ---
 drivers/gpu/drm/i915/display/intel_sprite.h   | 10 
 4 files changed, 97 insertions(+), 17 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..fd1a97b9e653 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)
}
 }
 
+#if IS_ENABLED(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, "\t1us (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..eef3b1fa7e92 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 long over_vbl_time;
+   unsigned int vbl_times[21]; /* [1us, 1ms] */
+#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..f6e1861f3c31 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 

[Intel-gfx] [PATCH] drm/i915/display: Record the plane update times for debugging

2020-11-26 Thread Chris Wilson
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 
Cc: Jani Nikula 
Cc: Ville Syrjälä 
---
 .../drm/i915/display/intel_display_debugfs.c  | 48 +++
 .../drm/i915/display/intel_display_types.h|  7 +++
 drivers/gpu/drm/i915/display/intel_sprite.c   | 44 ++---
 drivers/gpu/drm/i915/display/intel_sprite.h   | 10 
 4 files changed, 92 insertions(+), 17 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..fd1a97b9e653 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)
}
 }
 
+#if IS_ENABLED(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, "\t1us (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..eef3b1fa7e92 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 long over_vbl_time;
+   unsigned int vbl_times[21]; /* [1us, 1ms] */
+#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..7c6d95167e56 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 t

[Intel-gfx] [PATCH] drm/i915/display: Record the plane update times for debugging

2020-11-25 Thread Chris Wilson
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 
Cc: Jani Nikula 
Cc: Ville Syrjälä 
---
 .../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, "\t1us (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 spinlock

[Intel-gfx] [PATCH] drm/i915/display: Record the plane update times for debugging

2020-11-24 Thread Chris Wilson
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 
Cc: Jani Nikula 
Cc: Ville Syrjälä 
---
 .../drm/i915/display/intel_display_debugfs.c  | 47 +++
 .../drm/i915/display/intel_display_types.h|  7 +++
 drivers/gpu/drm/i915/display/intel_sprite.c   | 29 +---
 3 files changed, 76 insertions(+), 7 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..b29136208d56 100644
--- a/drivers/gpu/drm/i915/display/intel_display_debugfs.c
+++ b/drivers/gpu/drm/i915/display/intel_display_debugfs.c
@@ -865,6 +865,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, "\t1us (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 +952,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..661cbaf4cc38 100644
--- a/drivers/gpu/drm/i915/display/intel_sprite.c
+++ b/drivers/gpu/drm/i915/display/intel_sprite.c
@@ -250,13 +250,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",
-

[Intel-gfx] [PATCH] drm/i915/display: Record the plane update times for debugging

2020-11-23 Thread Chris Wilson
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.

Signed-off-by: Chris Wilson 
Cc: Jani Nikula 
Cc: Ville Syrjälä 
---
 .../drm/i915/display/intel_display_debugfs.c  | 46 +++
 .../drm/i915/display/intel_display_types.h|  6 +++
 drivers/gpu/drm/i915/display/intel_sprite.c   | 26 ---
 3 files changed, 71 insertions(+), 7 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..aa7a2a679138 100644
--- a/drivers/gpu/drm/i915/display/intel_display_debugfs.c
+++ b/drivers/gpu/drm/i915/display/intel_display_debugfs.c
@@ -865,6 +865,50 @@ 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);
+
+   max = ilog2(max);
+   for (row = max - 1; 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, "\t1us (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));
+}
+#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 +951,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..01214636be56 100644
--- a/drivers/gpu/drm/i915/display/intel_display_types.h
+++ b/drivers/gpu/drm/i915/display/intel_display_types.h
@@ -1186,6 +1186,12 @@ 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[20]; /* [1us, 1ms] */
+#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..fdb54a569224 100644
--- a/drivers/gpu/drm/i915/display/intel_sprite.c
+++ b/drivers/gpu/drm/i915/display/intel_sprite.c
@@ -250,13 +250,25 @@ 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;
+