Re: [PATCH 5/6] drm: Prevent vblank counter jumps with timestamp based update method.

[Daniel Vetter <daniel@ffwll.ch>]

On Mon, Feb 08, 2016 at 02:13:28AM +0100, Mario Kleiner wrote:
> The changes to drm_update_vblank_count() in Linux 4.4 added a
> method to emulate a hardware vblank counter by use of high
> precision vblank timestamps if a kms driver supports those,
> but doesn't suppport hw vblank counters.
> 
> That method assumes that the old timestamp from a previous
> invocation is valid, but that is not always the case. E.g.,
> if drm_reset_vblank_timestamp() gets called during drm_vblank_on()
> or drm_update_vblank_count() gets called outside vblank irq and
> the high precision timestamping can't deliver a precise timestamp,
> ie. drm_get_last_vbltimestamp() delivers a return value of false,
> then those functions will initialize the old timestamp to zero
> to mark it as invalid.
> 
> A following call to drm_update_vblank_count() would then calculate
> elapsed time with vblank irqs off as current vblank timestamp minus
> the zero old timestamp and compute a software vblank counter increment
> that corresponds to system uptime, causing a large forward jump of the
> software vblank counter. That jump in turn can cause too long waits
> in drmWaitVblank and very long delays in delivery of vblank events,
> resulting in hangs of userspace clients.
> 
> This problem can be observed on nouveau-kms during machine
> suspend->resume cycles, where drm_vblank_off is called during
> suspend, drm_vblank_on is called during resume and the first
> queries to drm_get_last_vbltimestamp() don't deliver high
> precision timestamps, resulting in a large harmful counter jump.

Why does nouveau enable vblank interrupts before it can get valid
timestamps? That sounds like the core bug here, and papering over that in
the vblank code feels very wrong to me. Maybe we should instead just not
sample the vblank at all if the timestamp fails and splat a big WARN_ON
about this, to give driver writers a chance to fix up their mess?
-Daniel

> 
> Fix this by checking if the old timestamp used for this calculations
> is zero == invalid. If so, perform a counter increment of +1 to
> prevent large counter jumps and reinitialize the timestamps to
> sane values.
> 
> Signed-off-by: Mario Kleiner <mario.kleiner.de@gmail.com>
> Cc: <stable@vger.kernel.org> # 4.4+
> Cc: michel@daenzer.net
> Cc: vbabka@suse.cz
> Cc: ville.syrjala@linux.intel.com
> Cc: daniel.vetter@ffwll.ch
> Cc: dri-devel@lists.freedesktop.org
> Cc: alexander.deucher@amd.com
> Cc: christian.koenig@amd.com
> ---
>  drivers/gpu/drm/drm_irq.c | 7 +++++++
>  1 file changed, 7 insertions(+)
> 
> diff --git a/drivers/gpu/drm/drm_irq.c b/drivers/gpu/drm/drm_irq.c
> index fb17c45..88bdf19 100644
> --- a/drivers/gpu/drm/drm_irq.c
> +++ b/drivers/gpu/drm/drm_irq.c
> @@ -216,6 +216,13 @@ static void drm_update_vblank_count(struct drm_device *dev, unsigned int pipe,
>  			DRM_DEBUG_VBL("crtc %u: Redundant vblirq ignored."
>  				      " diff_ns = %lld, framedur_ns = %d)\n",
>  				      pipe, (long long) diff_ns, framedur_ns);
> +
> +		/* No valid t_old to calculate diff? Bump +1 to force reinit. */
> +		if (t_old->tv_sec == 0 && t_old->tv_usec == 0) {
> +			DRM_DEBUG_VBL("crtc %u: No baseline ts. Bump +1.\n",
> +				      pipe);
> +			diff = 1;
> +		}
>  	} else {
>  		/* some kind of default for drivers w/o accurate vbl timestamping */
>  		diff = (flags & DRM_CALLED_FROM_VBLIRQ) != 0;
> -- 
> 1.9.1
> 

-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch