[PATCH] Attempt to detect and recover from pageflipping stalls

[PATCH] Attempt to detect and recover from pageflipping stalls

[Simon Farnsworth]

In an attempt to get to the bottom of bug #29798, Chris Wilson gave me
a patch that put some details in debugfs. With the clues gathered from
that patch, I was able to determine that the page flip is happening,
but that we're not seeing the IRQs we'd expect.

Work around this by only permitting a pageflip to be outstanding for 3
VBlank periods before we start examining the display registers to see
if the pageflip happened, but we weren't told about it. This converts
an apparent hang into a visual glitch.

Signed-off-by: Simon Farnsworth <simon.farnsworth@onelan.co.uk>
---
 drivers/gpu/drm/i915/i915_debugfs.c  |   45 +++++++++++++++++++++++++++
 drivers/gpu/drm/i915/i915_irq.c      |   56 ++++++++++++++++++++++++++++++++-
 drivers/gpu/drm/i915/intel_display.c |   15 +++------
 drivers/gpu/drm/i915/intel_drv.h     |   10 ++++++
 4 files changed, 114 insertions(+), 12 deletions(-)

diff --git a/drivers/gpu/drm/i915/i915_debugfs.c b/drivers/gpu/drm/i915/i915_debugfs.c
index 92d5605..2879ab1 100644
--- a/drivers/gpu/drm/i915/i915_debugfs.c
+++ b/drivers/gpu/drm/i915/i915_debugfs.c
@@ -33,6 +33,7 @@
 #include "drm.h"
 #include "i915_drm.h"
 #include "i915_drv.h"
+#include "intel_drv.h"
 
 #define DRM_I915_RING_DEBUG 1
 
@@ -121,6 +122,49 @@ static int i915_gem_object_list_info(struct seq_file *m, void *data)
 	return 0;
 }
 
+static int i915_gem_pageflip_info(struct seq_file *m, void *data)
+{
+	struct drm_info_node *node = (struct drm_info_node *) m->private;
+	struct drm_device *dev = node->minor->dev;
+	unsigned long flags;
+	struct intel_crtc *crtc;
+
+	list_for_each_entry(crtc, &dev->mode_config.crtc_list, base.head) {
+		const char *pipe = crtc->pipe ? "B" : "A";
+		const char *plane = crtc->plane ? "B" : "A";
+		struct intel_unpin_work *work;
+
+		spin_lock_irqsave(&dev->event_lock, flags);
+		work = crtc->unpin_work;
+		if (work == NULL) {
+			seq_printf(m, "No flip due on pipe %s (plane %s)\n",
+				   pipe, plane);
+		} else {
+			if (!work->pending) {
+				seq_printf(m, "Flip queued on pipe %s (plane %s)\n",
+					   pipe, plane);
+			} else {
+				seq_printf(m, "Flip pending (waiting for vsync) on pipe %s (plane %s)\n",
+					   pipe, plane);
+			}
+			seq_printf(m, "%d vblanks before missed interrupt check, %d prepares\n", work->stall_check_vblanks, work->pending);
+			if (work->old_fb_obj) {
+				struct drm_i915_gem_object *obj_priv = to_intel_bo(work->old_fb_obj);
+				if(obj_priv)
+					seq_printf(m, "Old framebuffer gtt_offset 0x%08x\n", obj_priv->gtt_offset );
+			}
+			if (work->pending_flip_obj) {
+				struct drm_i915_gem_object *obj_priv = to_intel_bo(work->pending_flip_obj);
+				if(obj_priv)
+					seq_printf(m, "New framebuffer gtt_offset 0x%08x\n", obj_priv->gtt_offset );
+			}
+		}
+		spin_unlock_irqrestore(&dev->event_lock, flags);
+	}
+
+	return 0;
+}
+
 static int i915_gem_request_info(struct seq_file *m, void *data)
 {
 	struct drm_info_node *node = (struct drm_info_node *) m->private;
@@ -777,6 +821,7 @@ static struct drm_info_list i915_debugfs_list[] = {
 	{"i915_gem_active", i915_gem_object_list_info, 0, (void *) ACTIVE_LIST},
 	{"i915_gem_flushing", i915_gem_object_list_info, 0, (void *) FLUSHING_LIST},
 	{"i915_gem_inactive", i915_gem_object_list_info, 0, (void *) INACTIVE_LIST},
+	{"i915_gem_pageflip", i915_gem_pageflip_info, 0},
 	{"i915_gem_request", i915_gem_request_info, 0},
 	{"i915_gem_seqno", i915_gem_seqno_info, 0},
 	{"i915_gem_fence_regs", i915_gem_fence_regs_info, 0},
diff --git a/drivers/gpu/drm/i915/i915_irq.c b/drivers/gpu/drm/i915/i915_irq.c
index 16861b8..893cd77 100644
--- a/drivers/gpu/drm/i915/i915_irq.c
+++ b/drivers/gpu/drm/i915/i915_irq.c
@@ -887,6 +887,54 @@ static void i915_handle_error(struct drm_device *dev, bool wedged)
 	queue_work(dev_priv->wq, &dev_priv->error_work);
 }
 
+static void i915_pageflip_stall_check(struct drm_device *dev, int pipe)
+{
+	drm_i915_private_t *dev_priv = dev->dev_private;
+	struct drm_crtc *crtc = dev_priv->pipe_to_crtc_mapping[pipe];
+	int plane = intel_crtc->plane;
+	struct intel_crtc *intel_crtc = to_intel_crtc(crtc);
+	unsigned long flags;
+	bool stall_detected = false;
+	struct drm_i915_gem_object *obj_priv;
+
+	/* Ignore early vblank irqs */
+	if (intel_crtc == NULL)
+		return;
+
+	spin_lock_irqsave(&dev->event_lock, flags);
+	work = intel_crtc->unpin_work;
+
+	if (work == NULL || work->pending || !work->pending_flip_obj) {
+		/* Not started - can't have stalled */
+		spin_unlock_irqrestore(&dev->event_lock, flags);
+		return;
+	}
+	if (work->stall_check_vblanks > 0) {
+		--work->stall_check_vblanks;
+		spin_unlock_irqrestore(&dev->event_lock, flags);
+		return;
+	}
+
+	/* Potential stall */
+	obj_priv = to_intel_bo(work->pending_flip_obj);
+	if(IS_I965G(dev)) {
+		int dspsurf = (plane == 0 ? DSPASURF : DSPBSURF);
+		stall_detected = I915_READ(dspsurf) == obj_priv->gtt_offset;
+	}
+	else {
+		int dspaddr = (plane == 0 ? DSPAADDR : DSPBADDR);
+		stall_detected = I915_READ(dspaddr) == (obj_priv->gtt_offset +
+							crtc->y * crtc->fb->pitch +
+							crtc->x * crtc->fb->bits_per_pixel/8);
+	}
+
+	spin_unlock_irqrestore(&dev->event_lock, flags);
+
+	if (stall_detected)
+		intel_prepare_page_flip(dev, plane);
+	return;
+}
+
 irqreturn_t i915_driver_irq_handler(DRM_IRQ_ARGS)
 {
 	struct drm_device *dev = (struct drm_device *) arg;
@@ -1004,15 +1052,19 @@ irqreturn_t i915_driver_irq_handler(DRM_IRQ_ARGS)
 		if (pipea_stats & vblank_status) {
 			vblank++;
 			drm_handle_vblank(dev, 0);
-			if (!dev_priv->flip_pending_is_done)
+			if (!dev_priv->flip_pending_is_done) {
+				i915_pageflip_stall_check(dev, 0);
 				intel_finish_page_flip(dev, 0);
+			}
 		}
 
 		if (pipeb_stats & vblank_status) {
 			vblank++;
 			drm_handle_vblank(dev, 1);
-			if (!dev_priv->flip_pending_is_done)
+			if (!dev_priv->flip_pending_is_done) {
+				i915_pageflip_stall_check(dev, 1);
 				intel_finish_page_flip(dev, 1);
+			}
 		}
 
 		if ((pipea_stats & PIPE_LEGACY_BLC_EVENT_STATUS) ||
diff --git a/drivers/gpu/drm/i915/intel_display.c b/drivers/gpu/drm/i915/intel_display.c
index 23157e1..c8f2624 100644
--- a/drivers/gpu/drm/i915/intel_display.c
+++ b/drivers/gpu/drm/i915/intel_display.c
@@ -4911,15 +4911,6 @@ static void intel_crtc_destroy(struct drm_crtc *crtc)
 	kfree(intel_crtc);
 }
 
-struct intel_unpin_work {
-	struct work_struct work;
-	struct drm_device *dev;
-	struct drm_gem_object *old_fb_obj;
-	struct drm_gem_object *pending_flip_obj;
-	struct drm_pending_vblank_event *event;
-	int pending;
-};
-
 static void intel_unpin_work_fn(struct work_struct *__work)
 {
 	struct intel_unpin_work *work =
@@ -5007,7 +4998,7 @@ void intel_prepare_page_flip(struct drm_device *dev, int plane)
 
 	spin_lock_irqsave(&dev->event_lock, flags);
 	if (intel_crtc->unpin_work) {
-		intel_crtc->unpin_work->pending = 1;
+		++intel_crtc->unpin_work->pending;
 	} else {
 		DRM_DEBUG_DRIVER("preparing flip with no unpin work?\n");
 	}
@@ -5049,6 +5040,10 @@ static int intel_crtc_page_flip(struct drm_crtc *crtc,
 		DRM_DEBUG_DRIVER("flip queue: crtc already busy\n");
 		return -EBUSY;
 	}
+	/* Long enough to allow for one coming in while we were setting this up,
+	   one while we fill in the ring, and finally the one that should have
+	   resulted in the flip happening */
+	work->stall_check_vblanks = 3;
 	intel_crtc->unpin_work = work;
 	spin_unlock_irqrestore(&dev->event_lock, flags);
 
diff --git a/drivers/gpu/drm/i915/intel_drv.h b/drivers/gpu/drm/i915/intel_drv.h
index 0e92aa0..db8725b 100644
--- a/drivers/gpu/drm/i915/intel_drv.h
+++ b/drivers/gpu/drm/i915/intel_drv.h
@@ -176,6 +176,16 @@ struct intel_crtc {
 #define enc_to_intel_encoder(x) container_of(x, struct intel_encoder, enc)
 #define to_intel_framebuffer(x) container_of(x, struct intel_framebuffer, base)
 
+struct intel_unpin_work {
+	struct work_struct work;
+	struct drm_device *dev;
+	struct drm_gem_object *old_fb_obj;
+	struct drm_gem_object *pending_flip_obj;
+	struct drm_pending_vblank_event *event;
+	int pending;
+	int stall_check_vblanks;
+};
+
 struct i2c_adapter *intel_i2c_create(struct drm_device *dev, const u32 reg,
 				     const char *name);
 void intel_i2c_destroy(struct i2c_adapter *adapter);
-- 
1.7.0.1

Re: [PATCH] Attempt to detect and recover from pageflipping stalls

[Simon Farnsworth]

On Wednesday 1 September 2010, Simon Farnsworth 
<simon.farnsworth@onelan.co.uk> wrote:
> In an attempt to get to the bottom of bug #29798, Chris Wilson gave me
> a patch that put some details in debugfs. With the clues gathered from
> that patch, I was able to determine that the page flip is happening,
> but that we're not seeing the IRQs we'd expect.
> 
> Work around this by only permitting a pageflip to be outstanding for 3
> VBlank periods before we start examining the display registers to see
> if the pageflip happened, but we weren't told about it. This converts
> an apparent hang into a visual glitch.
> 

I should note that this patch is under-tested, and intended to provoke 
discussion.

> Signed-off-by: Simon Farnsworth <simon.farnsworth@onelan.co.uk>
> ---
>  drivers/gpu/drm/i915/i915_debugfs.c  |   45 +++++++++++++++++++++++++++
>  drivers/gpu/drm/i915/i915_irq.c      |   56
> ++++++++++++++++++++++++++++++++- drivers/gpu/drm/i915/intel_display.c |  
> 15 +++------
>  drivers/gpu/drm/i915/intel_drv.h     |   10 ++++++
>  4 files changed, 114 insertions(+), 12 deletions(-)
> 
> diff --git a/drivers/gpu/drm/i915/i915_debugfs.c
> b/drivers/gpu/drm/i915/i915_debugfs.c index 92d5605..2879ab1 100644
> --- a/drivers/gpu/drm/i915/i915_debugfs.c
> +++ b/drivers/gpu/drm/i915/i915_debugfs.c
> @@ -33,6 +33,7 @@
>  #include "drm.h"
>  #include "i915_drm.h"
>  #include "i915_drv.h"
> +#include "intel_drv.h"
> 
>  #define DRM_I915_RING_DEBUG 1
> 
> @@ -121,6 +122,49 @@ static int i915_gem_object_list_info(struct seq_file
> *m, void *data) return 0;
>  }
> 
> +static int i915_gem_pageflip_info(struct seq_file *m, void *data)
> +{
> +	struct drm_info_node *node = (struct drm_info_node *) m->private;
> +	struct drm_device *dev = node->minor->dev;
> +	unsigned long flags;
> +	struct intel_crtc *crtc;
> +
> +	list_for_each_entry(crtc, &dev->mode_config.crtc_list, base.head) {
> +		const char *pipe = crtc->pipe ? "B" : "A";
> +		const char *plane = crtc->plane ? "B" : "A";
> +		struct intel_unpin_work *work;
> +
> +		spin_lock_irqsave(&dev->event_lock, flags);
> +		work = crtc->unpin_work;
> +		if (work == NULL) {
> +			seq_printf(m, "No flip due on pipe %s (plane %s)\n",
> +				   pipe, plane);
> +		} else {
> +			if (!work->pending) {
> +				seq_printf(m, "Flip queued on pipe %s (plane %s)\n",
> +					   pipe, plane);
> +			} else {
> +				seq_printf(m, "Flip pending (waiting for vsync) on pipe %s 
(plane
> %s)\n", +					   pipe, plane);
> +			}
> +			seq_printf(m, "%d vblanks before missed interrupt check, %d
> prepares\n", work->stall_check_vblanks, work->pending); +			if
> (work->old_fb_obj) {
> +				struct drm_i915_gem_object *obj_priv = to_intel_bo(work-
>old_fb_obj);
> +				if(obj_priv)
> +					seq_printf(m, "Old framebuffer gtt_offset 0x%08x\n",
> obj_priv->gtt_offset ); +			}
> +			if (work->pending_flip_obj) {
> +				struct drm_i915_gem_object *obj_priv =
> to_intel_bo(work->pending_flip_obj); +				if(obj_priv)
> +					seq_printf(m, "New framebuffer gtt_offset 0x%08x\n",
> obj_priv->gtt_offset ); +			}
> +		}
> +		spin_unlock_irqrestore(&dev->event_lock, flags);
> +	}
> +
> +	return 0;
> +}
> +
>  static int i915_gem_request_info(struct seq_file *m, void *data)
>  {
>  	struct drm_info_node *node = (struct drm_info_node *) m->private;
> @@ -777,6 +821,7 @@ static struct drm_info_list i915_debugfs_list[] = {
>  	{"i915_gem_active", i915_gem_object_list_info, 0, (void *) ACTIVE_LIST},
>  	{"i915_gem_flushing", i915_gem_object_list_info, 0, (void *)
> FLUSHING_LIST}, {"i915_gem_inactive", i915_gem_object_list_info, 0, (void
> *) INACTIVE_LIST}, +	{"i915_gem_pageflip", i915_gem_pageflip_info, 0},
>  	{"i915_gem_request", i915_gem_request_info, 0},
>  	{"i915_gem_seqno", i915_gem_seqno_info, 0},
>  	{"i915_gem_fence_regs", i915_gem_fence_regs_info, 0},
> diff --git a/drivers/gpu/drm/i915/i915_irq.c
> b/drivers/gpu/drm/i915/i915_irq.c index 16861b8..893cd77 100644
> --- a/drivers/gpu/drm/i915/i915_irq.c
> +++ b/drivers/gpu/drm/i915/i915_irq.c
> @@ -887,6 +887,54 @@ static void i915_handle_error(struct drm_device *dev,
> bool wedged) queue_work(dev_priv->wq, &dev_priv->error_work);
>  }
> 
> +static void i915_pageflip_stall_check(struct drm_device *dev, int pipe)
> +{
> +	drm_i915_private_t *dev_priv = dev->dev_private;
> +	struct drm_crtc *crtc = dev_priv->pipe_to_crtc_mapping[pipe];
> +	int plane = intel_crtc->plane;
> +	struct intel_crtc *intel_crtc = to_intel_crtc(crtc);
> +	unsigned long flags;
> +	bool stall_detected = false;
> +	struct drm_i915_gem_object *obj_priv;
> +
> +	/* Ignore early vblank irqs */
> +	if (intel_crtc == NULL)
> +		return;
> +
> +	spin_lock_irqsave(&dev->event_lock, flags);
> +	work = intel_crtc->unpin_work;
> +
> +	if (work == NULL || work->pending || !work->pending_flip_obj) {
> +		/* Not started - can't have stalled */
> +		spin_unlock_irqrestore(&dev->event_lock, flags);
> +		return;
> +	}
> +	if (work->stall_check_vblanks > 0) {
> +		--work->stall_check_vblanks;
> +		spin_unlock_irqrestore(&dev->event_lock, flags);
> +		return;
> +	}
> +
> +	/* Potential stall */
> +	obj_priv = to_intel_bo(work->pending_flip_obj);
> +	if(IS_I965G(dev)) {
> +		int dspsurf = (plane == 0 ? DSPASURF : DSPBSURF);
> +		stall_detected = I915_READ(dspsurf) == obj_priv->gtt_offset;
> +	}
> +	else {
> +		int dspaddr = (plane == 0 ? DSPAADDR : DSPBADDR);
> +		stall_detected = I915_READ(dspaddr) == (obj_priv->gtt_offset +
> +							crtc->y * crtc->fb->pitch +
> +							crtc->x * crtc->fb->bits_per_pixel/8);
> +	}
> +
> +	spin_unlock_irqrestore(&dev->event_lock, flags);
> +
> +	if (stall_detected)
> +		intel_prepare_page_flip(dev, plane);
> +	return;
> +}
> +
>  irqreturn_t i915_driver_irq_handler(DRM_IRQ_ARGS)
>  {
>  	struct drm_device *dev = (struct drm_device *) arg;
> @@ -1004,15 +1052,19 @@ irqreturn_t i915_driver_irq_handler(DRM_IRQ_ARGS)
>  		if (pipea_stats & vblank_status) {
>  			vblank++;
>  			drm_handle_vblank(dev, 0);
> -			if (!dev_priv->flip_pending_is_done)
> +			if (!dev_priv->flip_pending_is_done) {
> +				i915_pageflip_stall_check(dev, 0);
>  				intel_finish_page_flip(dev, 0);
> +			}
>  		}
> 
>  		if (pipeb_stats & vblank_status) {
>  			vblank++;
>  			drm_handle_vblank(dev, 1);
> -			if (!dev_priv->flip_pending_is_done)
> +			if (!dev_priv->flip_pending_is_done) {
> +				i915_pageflip_stall_check(dev, 1);
>  				intel_finish_page_flip(dev, 1);
> +			}
>  		}
> 
>  		if ((pipea_stats & PIPE_LEGACY_BLC_EVENT_STATUS) ||
> diff --git a/drivers/gpu/drm/i915/intel_display.c
> b/drivers/gpu/drm/i915/intel_display.c index 23157e1..c8f2624 100644
> --- a/drivers/gpu/drm/i915/intel_display.c
> +++ b/drivers/gpu/drm/i915/intel_display.c
> @@ -4911,15 +4911,6 @@ static void intel_crtc_destroy(struct drm_crtc
> *crtc) kfree(intel_crtc);
>  }
> 
> -struct intel_unpin_work {
> -	struct work_struct work;
> -	struct drm_device *dev;
> -	struct drm_gem_object *old_fb_obj;
> -	struct drm_gem_object *pending_flip_obj;
> -	struct drm_pending_vblank_event *event;
> -	int pending;
> -};
> -
>  static void intel_unpin_work_fn(struct work_struct *__work)
>  {
>  	struct intel_unpin_work *work =
> @@ -5007,7 +4998,7 @@ void intel_prepare_page_flip(struct drm_device *dev,
> int plane)
> 
>  	spin_lock_irqsave(&dev->event_lock, flags);
>  	if (intel_crtc->unpin_work) {
> -		intel_crtc->unpin_work->pending = 1;
> +		++intel_crtc->unpin_work->pending;
>  	} else {
>  		DRM_DEBUG_DRIVER("preparing flip with no unpin work?\n");
>  	}
> @@ -5049,6 +5040,10 @@ static int intel_crtc_page_flip(struct drm_crtc
> *crtc, DRM_DEBUG_DRIVER("flip queue: crtc already busy\n");
>  		return -EBUSY;
>  	}
> +	/* Long enough to allow for one coming in while we were setting this up,
> +	   one while we fill in the ring, and finally the one that should have
> +	   resulted in the flip happening */
> +	work->stall_check_vblanks = 3;
>  	intel_crtc->unpin_work = work;
>  	spin_unlock_irqrestore(&dev->event_lock, flags);
> 
> diff --git a/drivers/gpu/drm/i915/intel_drv.h
> b/drivers/gpu/drm/i915/intel_drv.h index 0e92aa0..db8725b 100644
> --- a/drivers/gpu/drm/i915/intel_drv.h
> +++ b/drivers/gpu/drm/i915/intel_drv.h
> @@ -176,6 +176,16 @@ struct intel_crtc {
>  #define enc_to_intel_encoder(x) container_of(x, struct intel_encoder, enc)
>  #define to_intel_framebuffer(x) container_of(x, struct intel_framebuffer,
> base)
> 
> +struct intel_unpin_work {
> +	struct work_struct work;
> +	struct drm_device *dev;
> +	struct drm_gem_object *old_fb_obj;
> +	struct drm_gem_object *pending_flip_obj;
> +	struct drm_pending_vblank_event *event;
> +	int pending;
> +	int stall_check_vblanks;
> +};
> +
>  struct i2c_adapter *intel_i2c_create(struct drm_device *dev, const u32
> reg, const char *name);
>  void intel_i2c_destroy(struct i2c_adapter *adapter);
-- 
Simon Farnsworth
Software Engineer
ONELAN Limited
http://www.onelan.com/

Re: [PATCH] Attempt to detect and recover from pageflipping stalls

[Simon Farnsworth]

On Wednesday 1 September 2010, Simon Farnsworth 
<simon.farnsworth@onelan.co.uk> wrote:
> In an attempt to get to the bottom of bug #29798, Chris Wilson gave me
> a patch that put some details in debugfs. With the clues gathered from
> that patch, I was able to determine that the page flip is happening,
> but that we're not seeing the IRQs we'd expect.
> 
> Work around this by only permitting a pageflip to be outstanding for 3
> VBlank periods before we start examining the display registers to see
> if the pageflip happened, but we weren't told about it. This converts
> an apparent hang into a visual glitch.
> 
And, as promised, it's buggy:

> diff --git a/drivers/gpu/drm/i915/i915_irq.c
> b/drivers/gpu/drm/i915/i915_irq.c index 16861b8..893cd77 100644
> --- a/drivers/gpu/drm/i915/i915_irq.c
> +++ b/drivers/gpu/drm/i915/i915_irq.c
> @@ -887,6 +887,54 @@ static void i915_handle_error(struct drm_device *dev,
> bool wedged) queue_work(dev_priv->wq, &dev_priv->error_work);
>  }
> 
> +static void i915_pageflip_stall_check(struct drm_device *dev, int pipe)
> +{
> +	drm_i915_private_t *dev_priv = dev->dev_private;
> +	struct drm_crtc *crtc = dev_priv->pipe_to_crtc_mapping[pipe];
> +	int plane = intel_crtc->plane;
> +	struct intel_crtc *intel_crtc = to_intel_crtc(crtc);

These two lines got swapped when I was checking various possible null 
pointers.

I can send a new version if required.
-- 
Simon Farnsworth
Software Engineer
ONELAN Limited
http://www.onelan.com/