drm/i915: Also record time difference if vblank evasion fails, v2.

This makes the error message slightly more useful.

Changes since v1:
- Use ktime_get() while irqs are still disabled. (vsyrjala)

Signed-off-by: Maarten Lankhorst <maarten.lankhorst@linux.intel.com>
Reviewed-by: Ville Syrjälä <ville.syrjala@linux.intel.com>
Signed-off-by: Daniel Vetter <daniel.vetter@ffwll.ch>

2 files changed, 7 insertions, 2 deletions

diff --git a/drivers/gpu/drm/i915/intel_drv.h b/drivers/gpu/drm/i915/intel_drv.h
index 8f8d320486ff..090d67b04307 100644
--- a/drivers/gpu/drm/i915/intel_drv.h
+++ b/drivers/gpu/drm/i915/intel_drv.h
@@ -564,6 +564,8 @@ struct intel_crtc {
         int scanline_offset;
 
         unsigned start_vbl_count;
+        ktime_t start_vbl_time;
+
         struct intel_crtc_atomic_commit atomic;
 
         /* scalers available on this crtc */
diff --git a/drivers/gpu/drm/i915/intel_sprite.c b/drivers/gpu/drm/i915/intel_sprite.c
index c35c2339f472..ca7e26430e66 100644
--- a/drivers/gpu/drm/i915/intel_sprite.c
+++ b/drivers/gpu/drm/i915/intel_sprite.c
@@ -134,6 +134,7 @@ void intel_pipe_update_start(struct intel_crtc *crtc)
 
         drm_crtc_vblank_put(&crtc->base);
 
+        crtc->start_vbl_time = ktime_get();
         crtc->start_vbl_count = dev->driver->get_vblank_counter(dev, pipe);
 
         trace_i915_pipe_update_vblank_evaded(crtc, min, max,
@@ -154,14 +155,16 @@ void intel_pipe_update_end(struct intel_crtc *crtc)
         struct drm_device *dev = crtc->base.dev;
         enum pipe pipe = crtc->pipe;
         u32 end_vbl_count = dev->driver->get_vblank_counter(dev, pipe);
+        ktime_t end_vbl_time = ktime_get();
 
         trace_i915_pipe_update_end(crtc, end_vbl_count);
 
         local_irq_enable();
 
         if (crtc->start_vbl_count && crtc->start_vbl_count != end_vbl_count)
-                DRM_ERROR("Atomic update failure on pipe %c (start=%u end=%u)\n",
-                          pipe_name(pipe), crtc->start_vbl_count, end_vbl_count);
+                DRM_ERROR("Atomic update failure on pipe %c (start=%u end=%u) time %lld us\n",
+                          pipe_name(pipe), crtc->start_vbl_count, end_vbl_count,
+                          ktime_us_delta(end_vbl_time, crtc->start_vbl_time));
 }
 
 static void