[PATCH] drm/imx: correct order of crtc disable

[PATCH] drm/imx: correct order of crtc disable

[Robert Beckett]

Notify drm core before sending pending events during crtc disable.
This fixes the first event after disable having an old stale timestamp
by having drm_crtc_vblank_off update the timestamp to now.

This was seen while debugging weston log message:
Warning: computed repaint delay is insane: -8212 msec

Signed-off-by: Robert Beckett <bob.beckett@collabora.com>
---
 drivers/gpu/drm/imx/ipuv3-crtc.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/drivers/gpu/drm/imx/ipuv3-crtc.c b/drivers/gpu/drm/imx/ipuv3-crtc.c
index 9cc1d678674f..c436a28d50e4 100644
--- a/drivers/gpu/drm/imx/ipuv3-crtc.c
+++ b/drivers/gpu/drm/imx/ipuv3-crtc.c
@@ -91,14 +91,14 @@ static void ipu_crtc_atomic_disable(struct drm_crtc *crtc,
 	ipu_dc_disable(ipu);
 	ipu_prg_disable(ipu);
 
+	drm_crtc_vblank_off(crtc);
+
 	spin_lock_irq(&crtc->dev->event_lock);
-	if (crtc->state->event) {
+	if (crtc->state->event && !crtc->state->active) {
 		drm_crtc_send_vblank_event(crtc, crtc->state->event);
 		crtc->state->event = NULL;
 	}
 	spin_unlock_irq(&crtc->dev->event_lock);
-
-	drm_crtc_vblank_off(crtc);
 }
 
 static void imx_drm_crtc_reset(struct drm_crtc *crtc)
-- 
2.18.0

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH] drm/imx: correct order of crtc disable

[Philipp Zabel]

Hi Robert,

thank you for the patch.

On Tue, 2019-06-18 at 16:50 +0100, Robert Beckett wrote:
> Notify drm core before sending pending events during crtc disable.
> This fixes the first event after disable having an old stale timestamp
> by having drm_crtc_vblank_off update the timestamp to now.
> 
> This was seen while debugging weston log message:
> Warning: computed repaint delay is insane: -8212 msec
> 

Would you say this
Fixes: a474478642d5 ("drm/imx: fix crtc vblank state regression")
?

> Signed-off-by: Robert Beckett <bob.beckett@collabora.com>
> ---
>  drivers/gpu/drm/imx/ipuv3-crtc.c | 6 +++---
>  1 file changed, 3 insertions(+), 3 deletions(-)
> 
> diff --git a/drivers/gpu/drm/imx/ipuv3-crtc.c b/drivers/gpu/drm/imx/ipuv3-crtc.c
> index 9cc1d678674f..c436a28d50e4 100644
> --- a/drivers/gpu/drm/imx/ipuv3-crtc.c
> +++ b/drivers/gpu/drm/imx/ipuv3-crtc.c
> @@ -91,14 +91,14 @@ static void ipu_crtc_atomic_disable(struct drm_crtc *crtc,
>  	ipu_dc_disable(ipu);
>  	ipu_prg_disable(ipu);
>  
> +	drm_crtc_vblank_off(crtc);
> +

This is explained in the commit message and aligns with the
drm_crtc_state @event documentation.

>  	spin_lock_irq(&crtc->dev->event_lock);
> -	if (crtc->state->event) {
> +	if (crtc->state->event && !crtc->state->active) {

This is not mentioned though. 

If the pending event is not sent here, I assume it will be picked up by
.atomic_flush and will then be sent after the first EOF interrupt after
the modeset is complete. Can you explain this in the commit message?

With that,
Reviewed-by: Philipp Zabel <p.zabel@pengutronix.de>

>  		drm_crtc_send_vblank_event(crtc, crtc->state->event);
>  		crtc->state->event = NULL;
>  	}
>  	spin_unlock_irq(&crtc->dev->event_lock);
> -
> -	drm_crtc_vblank_off(crtc);
>  }
>  
>  static void imx_drm_crtc_reset(struct drm_crtc *crtc)

regards
Philipp
_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH] drm/imx: correct order of crtc disable

[Daniel Vetter]

On Wed, Jun 19, 2019 at 11:40 AM Philipp Zabel <p.zabel@pengutronix.de> wrote:
>
> Hi Robert,
>
> thank you for the patch.
>
> On Tue, 2019-06-18 at 16:50 +0100, Robert Beckett wrote:
> > Notify drm core before sending pending events during crtc disable.
> > This fixes the first event after disable having an old stale timestamp
> > by having drm_crtc_vblank_off update the timestamp to now.
> >
> > This was seen while debugging weston log message:
> > Warning: computed repaint delay is insane: -8212 msec
> >
>
> Would you say this
> Fixes: a474478642d5 ("drm/imx: fix crtc vblank state regression")
> ?
>
> > Signed-off-by: Robert Beckett <bob.beckett@collabora.com>
> > ---
> >  drivers/gpu/drm/imx/ipuv3-crtc.c | 6 +++---
> >  1 file changed, 3 insertions(+), 3 deletions(-)
> >
> > diff --git a/drivers/gpu/drm/imx/ipuv3-crtc.c b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > index 9cc1d678674f..c436a28d50e4 100644
> > --- a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > +++ b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > @@ -91,14 +91,14 @@ static void ipu_crtc_atomic_disable(struct drm_crtc *crtc,
> >       ipu_dc_disable(ipu);
> >       ipu_prg_disable(ipu);
> >
> > +     drm_crtc_vblank_off(crtc);
> > +
>
> This is explained in the commit message and aligns with the
> drm_crtc_state @event documentation.

This part here looks fishy. The drm_vblank.c code is supposed to do
the right thing, no matter where or when you ask it to generate an
event. It definitely shouldn't generate a timestamp that's a few
seconds too early. Bunch of options:
- there's a bug in drm_vblank.c and it's mixing up something and
generating a totally bogus value.
- there's a lie in your imx vblank code, which trips the drm_vblank.c
counter interpolation and results in a totally bogus value.

drm_vblank.c assumes that if you do claim to have a hw counter and
generate timestamps, that those are perfectly accurate. It only falls
back to guestimating using the system timer if that's not present.

Either way, this very much smells like papering over a bug if this
change indeed fixes your wrong vblank timestamps.

> >       spin_lock_irq(&crtc->dev->event_lock);
> > -     if (crtc->state->event) {
> > +     if (crtc->state->event && !crtc->state->active) {
>
> This is not mentioned though.
>
> If the pending event is not sent here, I assume it will be picked up by
> .atomic_flush and will then be sent after the first EOF interrupt after
> the modeset is complete. Can you explain this in the commit message?

Yeah looks correct (you only want to generate the event here when the
crtc stays off), if it gets re-enabled the event should only be
generated later on once that's all finished. But separate bugfix.
-Daniel

>
> With that,
> Reviewed-by: Philipp Zabel <p.zabel@pengutronix.de>
>
> >               drm_crtc_send_vblank_event(crtc, crtc->state->event);
> >               crtc->state->event = NULL;
> >       }
> >       spin_unlock_irq(&crtc->dev->event_lock);
> > -
> > -     drm_crtc_vblank_off(crtc);
> >  }
> >
> >  static void imx_drm_crtc_reset(struct drm_crtc *crtc)
>
> regards
> Philipp
> _______________________________________________
> dri-devel mailing list
> dri-devel@lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/dri-devel



-- 
Daniel Vetter
Software Engineer, Intel Corporation
+41 (0) 79 365 57 48 - http://blog.ffwll.ch
_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH] drm/imx: correct order of crtc disable

[Robert Beckett]

On Thu, 2019-06-20 at 10:50 +0200, Daniel Vetter wrote:
> On Wed, Jun 19, 2019 at 11:40 AM Philipp Zabel <
> p.zabel@pengutronix.de> wrote:
> > 
> > Hi Robert,
> > 
> > thank you for the patch.
> > 
> > On Tue, 2019-06-18 at 16:50 +0100, Robert Beckett wrote:
> > > Notify drm core before sending pending events during crtc
> > > disable.
> > > This fixes the first event after disable having an old stale
> > > timestamp
> > > by having drm_crtc_vblank_off update the timestamp to now.
> > > 
> > > This was seen while debugging weston log message:
> > > Warning: computed repaint delay is insane: -8212 msec
> > > 
> > 
> > Would you say this
> > Fixes: a474478642d5 ("drm/imx: fix crtc vblank state regression")
> > ?
> > 
> > > Signed-off-by: Robert Beckett <bob.beckett@collabora.com>
> > > ---
> > >  drivers/gpu/drm/imx/ipuv3-crtc.c | 6 +++---
> > >  1 file changed, 3 insertions(+), 3 deletions(-)
> > > 
> > > diff --git a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > index 9cc1d678674f..c436a28d50e4 100644
> > > --- a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > +++ b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > @@ -91,14 +91,14 @@ static void ipu_crtc_atomic_disable(struct
> > > drm_crtc *crtc,
> > >       ipu_dc_disable(ipu);
> > >       ipu_prg_disable(ipu);
> > > 
> > > +     drm_crtc_vblank_off(crtc);
> > > +
> > 
> > This is explained in the commit message and aligns with the
> > drm_crtc_state @event documentation.
> 
> This part here looks fishy. The drm_vblank.c code is supposed to do
> the right thing, no matter where or when you ask it to generate an
> event. It definitely shouldn't generate a timestamp that's a few
> seconds too early. Bunch of options:
> - there's a bug in drm_vblank.c and it's mixing up something and
> generating a totally bogus value.
> - there's a lie in your imx vblank code, which trips the drm_vblank.c
> counter interpolation and results in a totally bogus value.
> 
> drm_vblank.c assumes that if you do claim to have a hw counter and
> generate timestamps, that those are perfectly accurate. It only falls
> back to guestimating using the system timer if that's not present.
> 
> Either way, this very much smells like papering over a bug if this
> change indeed fixes your wrong vblank timestamps.
> 

A quick explaination of where the dodgy timestamp came from:
1. driver starts up
2. fbcon comes along and restores fbdev, enabling vblank
3. vblank_disable_fn fires via timer disabling vblank, keeping vblank
seq number and time set at current value
(some time later)
4. weston starts and does a modeset
5. atomic commit disables crtc while it does the modeset
6. ipu_crtc_atomic_disable sends vblank with old seq number and time

It turns out the actual fix for the old vblank is the next change,
which stops it being sent at all during the crtc disable as it is is
still active, it would then go through drm_crtc_vblank_off, reseting
the timestamp, and get delivered during the vblank enable as part of
the atomic commit.

So, in theory, we could just have the following change to fix the
specific issue of a stale timestamp.

However, given the documentation for the event in
include/drm/drm_crtc.h:

         *  - The event is for a CRTC which is being disabled through
this
         *    atomic commit. In that case the event can be send out any
time
         *    after the hardware has stopped scanning out the current
         *    framebuffers. It should contain the timestamp and counter
for the
         *    last vblank before the display pipeline was shut off. The
simplest
         *    way to achieve that is calling
drm_crtc_send_vblank_event()
         *    somewhen after drm_crtc_vblank_off() has been called.

This still seems like a sensible change for when the crtc is being
disabled.



> > >       spin_lock_irq(&crtc->dev->event_lock);
> > > -     if (crtc->state->event)
> > > {
> > > +     if (crtc->state->event && !crtc->state->active) {
> > 
> > This is not mentioned though.
> > 
> > If the pending event is not sent here, I assume it will be picked
> > up by
> > .atomic_flush and will then be sent after the first EOF interrupt
> > after
> > the modeset is complete. Can you explain this in the commit
> > message?
> 
> Yeah looks correct (you only want to generate the event here when the
> crtc stays off), if it gets re-enabled the event should only be
> generated later on once that's all finished. But separate bugfix.
> -Daniel
> 

It looks like this is actually the fix needed to avoid the bogus
timestamp.

I can split this patch up in to 2 commits if desired?

> > 
> > With that,
> > Reviewed-by: Philipp Zabel <p.zabel@pengutronix.de>
> > 
> > >               drm_crtc_send_vblank_event(crtc, crtc->state-
> > > >event);
> > >               crtc->state->event = NULL;
> > >       }
> > >       spin_unlock_irq(&crtc->dev->event_lock);
> > > -
> > > -     drm_crtc_vblank_off(crtc);
> > >  }
> > > 
> > >  static void imx_drm_crtc_reset(struct drm_crtc *crtc)
> > 
> > regards
> > Philipp
> > _______________________________________________
> > dri-devel mailing list
> > dri-devel@lists.freedesktop.org
> > https://lists.freedesktop.org/mailman/listinfo/dri-devel
> 
> 
> 

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH] drm/imx: correct order of crtc disable

[Philipp Zabel]

Hi Robert, Daniel,

On Thu, 2019-06-20 at 12:12 +0100, Robert Beckett wrote:
> On Thu, 2019-06-20 at 10:50 +0200, Daniel Vetter wrote:
> > On Wed, Jun 19, 2019 at 11:40 AM Philipp Zabel <
> > p.zabel@pengutronix.de> wrote:
> > > 
> > > Hi Robert,
> > > 
> > > thank you for the patch.
> > > 
> > > On Tue, 2019-06-18 at 16:50 +0100, Robert Beckett wrote:
> > > > Notify drm core before sending pending events during crtc
> > > > disable.
> > > > This fixes the first event after disable having an old stale
> > > > timestamp
> > > > by having drm_crtc_vblank_off update the timestamp to now.
> > > > 
> > > > This was seen while debugging weston log message:
> > > > Warning: computed repaint delay is insane: -8212 msec
> > > > 
> > > 
> > > Would you say this
> > > Fixes: a474478642d5 ("drm/imx: fix crtc vblank state regression")
> > > ?
> > > 
> > > > Signed-off-by: Robert Beckett <bob.beckett@collabora.com>
> > > > ---
> > > >  drivers/gpu/drm/imx/ipuv3-crtc.c | 6 +++---
> > > >  1 file changed, 3 insertions(+), 3 deletions(-)
> > > > 
> > > > diff --git a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > index 9cc1d678674f..c436a28d50e4 100644
> > > > --- a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > +++ b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > @@ -91,14 +91,14 @@ static void ipu_crtc_atomic_disable(struct
> > > > drm_crtc *crtc,
> > > >       ipu_dc_disable(ipu);
> > > >       ipu_prg_disable(ipu);
> > > > 
> > > > +     drm_crtc_vblank_off(crtc);
> > > > +
> > > 
> > > This is explained in the commit message and aligns with the
> > > drm_crtc_state @event documentation.
> > 
> > This part here looks fishy. The drm_vblank.c code is supposed to do
> > the right thing, no matter where or when you ask it to generate an
> > event. It definitely shouldn't generate a timestamp that's a few
> > seconds too early. Bunch of options:
> > - there's a bug in drm_vblank.c and it's mixing up something and
> > generating a totally bogus value.
> > - there's a lie in your imx vblank code, which trips the drm_vblank.c
> > counter interpolation and results in a totally bogus value.
> > 
> > drm_vblank.c assumes that if you do claim to have a hw counter and
> > generate timestamps, that those are perfectly accurate. It only falls
> > back to guestimating using the system timer if that's not present.
> > 
> > Either way, this very much smells like papering over a bug if this
> > change indeed fixes your wrong vblank timestamps.

Thank you for chiming in, I can confirm that just moving the
drm_crtc_vblank_off around does not change anything.
I'll drop this patch and wait for v3.

> A quick explaination of where the dodgy timestamp came from:
> 1. driver starts up
> 2. fbcon comes along and restores fbdev, enabling vblank
> 3. vblank_disable_fn fires via timer disabling vblank, keeping vblank
> seq number and time set at current value
> (some time later)
> 4. weston starts and does a modeset
> 5. atomic commit disables crtc while it does the modeset
> 6. ipu_crtc_atomic_disable sends vblank with old seq number and time

It would be great to have this in the commit message for context.

> It turns out the actual fix for the old vblank is the next change,
> which stops it being sent at all during the crtc disable as it is is
> still active, it would then go through drm_crtc_vblank_off, reseting
> the timestamp, and get delivered during the vblank enable as part of
> the atomic commit.

Which means this patch isn't "Fixes: a474478642d5" after all.
The offending code has been there since commit 5f2f911578fb ("drm/imx:
atomic phase 3 step 1: Use atomic configuration").

> So, in theory, we could just have the following change to fix the
> specific issue of a stale timestamp.
>
> However, given the documentation for the event in
> include/drm/drm_crtc.h:
> 
>          *  - The event is for a CRTC which is being disabled through this
>          *    atomic commit. In that case the event can be send out any time
>          *    after the hardware has stopped scanning out the current 
>          *    framebuffers. It should contain the timestamp and counter for the
>          *    last vblank before the display pipeline was shut off. The simplest
>          *    way to achieve that is calling drm_crtc_send_vblank_event()
>          *    somewhen after drm_crtc_vblank_off() has been called.
> 
> This still seems like a sensible change for when the crtc is being
> disabled.

This is what had me confused as well. It doesn't really say, but it
seems to imply that drm_crtc_send_vblank_event must only be sent after
drm_crtc_vblank_off.
If this is not a hard requirement, maybe this could be mentioned here?

> > > >       spin_lock_irq(&crtc->dev->event_lock);
> > > > -     if (crtc->state->event)
> > > > {
> > > > +     if (crtc->state->event && !crtc->state->active) {
> > > 
> > > This is not mentioned though.
> > > 
> > > If the pending event is not sent here, I assume it will be picked
> > > up by
> > > .atomic_flush and will then be sent after the first EOF interrupt
> > > after
> > > the modeset is complete. Can you explain this in the commit
> > > message?
> > 
> > Yeah looks correct (you only want to generate the event here when the
> > crtc stays off), if it gets re-enabled the event should only be
> > generated later on once that's all finished. But separate bugfix.
> > -Daniel
> > 
> 
> It looks like this is actually the fix needed to avoid the bogus
> timestamp.
> 
> I can split this patch up in to 2 commits if desired?

Yes, please. The !state->active fix is stable material, moving
drm_crtc_vblank_off around apparently not so much.

regards
Philipp
_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH] drm/imx: correct order of crtc disable

[Daniel Vetter]

On Thu, Jun 20, 2019 at 12:12:13PM +0100, Robert Beckett wrote:
> On Thu, 2019-06-20 at 10:50 +0200, Daniel Vetter wrote:
> > On Wed, Jun 19, 2019 at 11:40 AM Philipp Zabel <
> > p.zabel@pengutronix.de> wrote:
> > > 
> > > Hi Robert,
> > > 
> > > thank you for the patch.
> > > 
> > > On Tue, 2019-06-18 at 16:50 +0100, Robert Beckett wrote:
> > > > Notify drm core before sending pending events during crtc
> > > > disable.
> > > > This fixes the first event after disable having an old stale
> > > > timestamp
> > > > by having drm_crtc_vblank_off update the timestamp to now.
> > > > 
> > > > This was seen while debugging weston log message:
> > > > Warning: computed repaint delay is insane: -8212 msec
> > > > 
> > > 
> > > Would you say this
> > > Fixes: a474478642d5 ("drm/imx: fix crtc vblank state regression")
> > > ?
> > > 
> > > > Signed-off-by: Robert Beckett <bob.beckett@collabora.com>
> > > > ---
> > > >  drivers/gpu/drm/imx/ipuv3-crtc.c | 6 +++---
> > > >  1 file changed, 3 insertions(+), 3 deletions(-)
> > > > 
> > > > diff --git a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > index 9cc1d678674f..c436a28d50e4 100644
> > > > --- a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > +++ b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > @@ -91,14 +91,14 @@ static void ipu_crtc_atomic_disable(struct
> > > > drm_crtc *crtc,
> > > >       ipu_dc_disable(ipu);
> > > >       ipu_prg_disable(ipu);
> > > > 
> > > > +     drm_crtc_vblank_off(crtc);
> > > > +
> > > 
> > > This is explained in the commit message and aligns with the
> > > drm_crtc_state @event documentation.
> > 
> > This part here looks fishy. The drm_vblank.c code is supposed to do
> > the right thing, no matter where or when you ask it to generate an
> > event. It definitely shouldn't generate a timestamp that's a few
> > seconds too early. Bunch of options:
> > - there's a bug in drm_vblank.c and it's mixing up something and
> > generating a totally bogus value.
> > - there's a lie in your imx vblank code, which trips the drm_vblank.c
> > counter interpolation and results in a totally bogus value.
> > 
> > drm_vblank.c assumes that if you do claim to have a hw counter and
> > generate timestamps, that those are perfectly accurate. It only falls
> > back to guestimating using the system timer if that's not present.
> > 
> > Either way, this very much smells like papering over a bug if this
> > change indeed fixes your wrong vblank timestamps.
> > 
> 
> A quick explaination of where the dodgy timestamp came from:
> 1. driver starts up
> 2. fbcon comes along and restores fbdev, enabling vblank
> 3. vblank_disable_fn fires via timer disabling vblank, keeping vblank
> seq number and time set at current value
> (some time later)
> 4. weston starts and does a modeset
> 5. atomic commit disables crtc while it does the modeset
> 6. ipu_crtc_atomic_disable sends vblank with old seq number and time
> 
> It turns out the actual fix for the old vblank is the next change,
> which stops it being sent at all during the crtc disable as it is is
> still active, it would then go through drm_crtc_vblank_off, reseting
> the timestamp, and get delivered during the vblank enable as part of
> the atomic commit.

This shouldn't fix your vblank timestamp troubles either. It might mean
that the timestamp is slightly too early (because you take it while
shutting down the crtc, not while re-enabling), but not by seconds.

Quick experiment: Disable vblank disabling with drm.vblankoffdelay = 0. If
that also fixes the timestamps, then I'm pretty sure you have a driver bug
somewhere and lie to the vblank core code about something.
-Daniel

> 
> So, in theory, we could just have the following change to fix the
> specific issue of a stale timestamp.
> 
> However, given the documentation for the event in
> include/drm/drm_crtc.h:
> 
>          *  - The event is for a CRTC which is being disabled through
> this
>          *    atomic commit. In that case the event can be send out any
> time
>          *    after the hardware has stopped scanning out the current
>          *    framebuffers. It should contain the timestamp and counter
> for the
>          *    last vblank before the display pipeline was shut off. The
> simplest
>          *    way to achieve that is calling
> drm_crtc_send_vblank_event()
>          *    somewhen after drm_crtc_vblank_off() has been called.
> 
> This still seems like a sensible change for when the crtc is being
> disabled.
> 
> 
> 
> > > >       spin_lock_irq(&crtc->dev->event_lock);
> > > > -     if (crtc->state->event)
> > > > {
> > > > +     if (crtc->state->event && !crtc->state->active) {
> > > 
> > > This is not mentioned though.
> > > 
> > > If the pending event is not sent here, I assume it will be picked
> > > up by
> > > .atomic_flush and will then be sent after the first EOF interrupt
> > > after
> > > the modeset is complete. Can you explain this in the commit
> > > message?
> > 
> > Yeah looks correct (you only want to generate the event here when the
> > crtc stays off), if it gets re-enabled the event should only be
> > generated later on once that's all finished. But separate bugfix.
> > -Daniel
> > 
> 
> It looks like this is actually the fix needed to avoid the bogus
> timestamp.
> 
> I can split this patch up in to 2 commits if desired?
> 
> > > 
> > > With that,
> > > Reviewed-by: Philipp Zabel <p.zabel@pengutronix.de>
> > > 
> > > >               drm_crtc_send_vblank_event(crtc, crtc->state-
> > > > >event);
> > > >               crtc->state->event = NULL;
> > > >       }
> > > >       spin_unlock_irq(&crtc->dev->event_lock);
> > > > -
> > > > -     drm_crtc_vblank_off(crtc);
> > > >  }
> > > > 
> > > >  static void imx_drm_crtc_reset(struct drm_crtc *crtc)
> > > 
> > > regards
> > > Philipp
> > > _______________________________________________
> > > dri-devel mailing list
> > > dri-devel@lists.freedesktop.org
> > > https://lists.freedesktop.org/mailman/listinfo/dri-devel
> > 
> > 
> > 
> 

-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH] drm/imx: correct order of crtc disable

[Robert Beckett]

On Thu, 2019-06-20 at 14:32 +0200, Daniel Vetter wrote:
> On Thu, Jun 20, 2019 at 12:12:13PM +0100, Robert Beckett wrote:
> > On Thu, 2019-06-20 at 10:50 +0200, Daniel Vetter wrote:
> > > On Wed, Jun 19, 2019 at 11:40 AM Philipp Zabel <
> > > p.zabel@pengutronix.de> wrote:
> > > > 
> > > > Hi Robert,
> > > > 
> > > > thank you for the patch.
> > > > 
> > > > On Tue, 2019-06-18 at 16:50 +0100, Robert Beckett wrote:
> > > > > Notify drm core before sending pending events during crtc
> > > > > disable.
> > > > > This fixes the first event after disable having an old stale
> > > > > timestamp
> > > > > by having drm_crtc_vblank_off update the timestamp to now.
> > > > > 
> > > > > This was seen while debugging weston log message:
> > > > > Warning: computed repaint delay is insane: -8212 msec
> > > > > 
> > > > 
> > > > Would you say this
> > > > Fixes: a474478642d5 ("drm/imx: fix crtc vblank state
> > > > regression")
> > > > ?
> > > > 
> > > > > Signed-off-by: Robert Beckett <bob.beckett@collabora.com>
> > > > > ---
> > > > >  drivers/gpu/drm/imx/ipuv3-crtc.c | 6 +++---
> > > > >  1 file changed, 3 insertions(+), 3 deletions(-)
> > > > > 
> > > > > diff --git a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > index 9cc1d678674f..c436a28d50e4 100644
> > > > > --- a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > +++ b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > @@ -91,14 +91,14 @@ static void
> > > > > ipu_crtc_atomic_disable(struct
> > > > > drm_crtc *crtc,
> > > > >       ipu_dc_disable(ipu);
> > > > >       ipu_prg_disable(ipu);
> > > > > 
> > > > > +     drm_crtc_vblank_off(crtc);
> > > > > +
> > > > 
> > > > This is explained in the commit message and aligns with the
> > > > drm_crtc_state @event documentation.
> > > 
> > > This part here looks fishy. The drm_vblank.c code is supposed to
> > > do
> > > the right thing, no matter where or when you ask it to generate
> > > an
> > > event. It definitely shouldn't generate a timestamp that's a few
> > > seconds too early. Bunch of options:
> > > - there's a bug in drm_vblank.c and it's mixing up something and
> > > generating a totally bogus value.
> > > - there's a lie in your imx vblank code, which trips the
> > > drm_vblank.c
> > > counter interpolation and results in a totally bogus value.
> > > 
> > > drm_vblank.c assumes that if you do claim to have a hw counter
> > > and
> > > generate timestamps, that those are perfectly accurate. It only
> > > falls
> > > back to guestimating using the system timer if that's not
> > > present.
> > > 
> > > Either way, this very much smells like papering over a bug if
> > > this
> > > change indeed fixes your wrong vblank timestamps.
> > > 
> > 
> > A quick explaination of where the dodgy timestamp came from:
> > 1. driver starts up
> > 2. fbcon comes along and restores fbdev, enabling vblank
> > 3. vblank_disable_fn fires via timer disabling vblank, keeping
> > vblank
> > seq number and time set at current value
> > (some time later)
> > 4. weston starts and does a modeset
> > 5. atomic commit disables crtc while it does the modeset
> > 6. ipu_crtc_atomic_disable sends vblank with old seq number and
> > time
> > 
> > It turns out the actual fix for the old vblank is the next change,
> > which stops it being sent at all during the crtc disable as it is
> > is
> > still active, it would then go through drm_crtc_vblank_off,
> > reseting
> > the timestamp, and get delivered during the vblank enable as part
> > of
> > the atomic commit.
> 
> This shouldn't fix your vblank timestamp troubles either. It might
> mean
> that the timestamp is slightly too early (because you take it while
> shutting down the crtc, not while re-enabling), but not by seconds.
> 
> Quick experiment: Disable vblank disabling with drm.vblankoffdelay =
> 0. If
> that also fixes the timestamps, then I'm pretty sure you have a
> driver bug
> somewhere and lie to the vblank core code about something.
> -Daniel
> 

Experiment done. The timestamp is fine, it is the timestamp of the
previous vblank update. But, this would fix it because the vblank
interrupt was never disabled.

The original issue was that the event got sent after vblank was
disabled and before it got re-enabled during the modeset, so nothing
had happened to update the timestamp and seq number.

What are you expecting to update the timestamp and seq number while the
interrupt is disabled after vblank_disable_fn?

Im struggling to see what this experiment was meant to test/prove.

> > 
> > So, in theory, we could just have the following change to fix the
> > specific issue of a stale timestamp.
> > 
> > However, given the documentation for the event in
> > include/drm/drm_crtc.h:
> > 
> >          *  - The event is for a CRTC which is being disabled
> > through
> > this
> >          *    atomic commit. In that case the event can be send out
> > any
> > time
> >          *    after the hardware has stopped scanning out the
> > current
> >          *    framebuffers. It should contain the timestamp and
> > counter
> > for the
> >          *    last vblank before the display pipeline was shut off.
> > The
> > simplest
> >          *    way to achieve that is calling
> > drm_crtc_send_vblank_event()
> >          *    somewhen after drm_crtc_vblank_off() has been called.
> > 
> > This still seems like a sensible change for when the crtc is being
> > disabled.
> > 
> > 
> > 
> > > > >       spin_lock_irq(&crtc->dev->event_lock);
> > > > > -     if (crtc->state->event)
> > > > > {
> > > > > +     if (crtc->state->event && !crtc->state->active) {
> > > > 
> > > > This is not mentioned though.
> > > > 
> > > > If the pending event is not sent here, I assume it will be
> > > > picked
> > > > up by
> > > > .atomic_flush and will then be sent after the first EOF
> > > > interrupt
> > > > after
> > > > the modeset is complete. Can you explain this in the commit
> > > > message?
> > > 
> > > Yeah looks correct (you only want to generate the event here when
> > > the
> > > crtc stays off), if it gets re-enabled the event should only be
> > > generated later on once that's all finished. But separate bugfix.
> > > -Daniel
> > > 
> > 
> > It looks like this is actually the fix needed to avoid the bogus
> > timestamp.
> > 
> > I can split this patch up in to 2 commits if desired?
> > 
> > > > 
> > > > With that,
> > > > Reviewed-by: Philipp Zabel <p.zabel@pengutronix.de>
> > > > 
> > > > >               drm_crtc_send_vblank_event(crtc, crtc->state-
> > > > > > event);
> > > > > 
> > > > >               crtc->state->event = NULL;
> > > > >       }
> > > > >       spin_unlock_irq(&crtc->dev->event_lock);
> > > > > -
> > > > > -     drm_crtc_vblank_off(crtc);
> > > > >  }
> > > > > 
> > > > >  static void imx_drm_crtc_reset(struct drm_crtc *crtc)
> > > > 
> > > > regards
> > > > Philipp
> > > > _______________________________________________
> > > > dri-devel mailing list
> > > > dri-devel@lists.freedesktop.org
> > > > https://lists.freedesktop.org/mailman/listinfo/dri-devel
> > > 
> > > 
> > > 
> 
> 

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH] drm/imx: correct order of crtc disable

[Daniel Vetter]

On Thu, Jun 20, 2019 at 3:30 PM Robert Beckett
<bob.beckett@collabora.com> wrote:
> On Thu, 2019-06-20 at 14:32 +0200, Daniel Vetter wrote:
> > On Thu, Jun 20, 2019 at 12:12:13PM +0100, Robert Beckett wrote:
> > > On Thu, 2019-06-20 at 10:50 +0200, Daniel Vetter wrote:
> > > > On Wed, Jun 19, 2019 at 11:40 AM Philipp Zabel <
> > > > p.zabel@pengutronix.de> wrote:
> > > > >
> > > > > Hi Robert,
> > > > >
> > > > > thank you for the patch.
> > > > >
> > > > > On Tue, 2019-06-18 at 16:50 +0100, Robert Beckett wrote:
> > > > > > Notify drm core before sending pending events during crtc
> > > > > > disable.
> > > > > > This fixes the first event after disable having an old stale
> > > > > > timestamp
> > > > > > by having drm_crtc_vblank_off update the timestamp to now.
> > > > > >
> > > > > > This was seen while debugging weston log message:
> > > > > > Warning: computed repaint delay is insane: -8212 msec
> > > > > >
> > > > >
> > > > > Would you say this
> > > > > Fixes: a474478642d5 ("drm/imx: fix crtc vblank state
> > > > > regression")
> > > > > ?
> > > > >
> > > > > > Signed-off-by: Robert Beckett <bob.beckett@collabora.com>
> > > > > > ---
> > > > > >  drivers/gpu/drm/imx/ipuv3-crtc.c | 6 +++---
> > > > > >  1 file changed, 3 insertions(+), 3 deletions(-)
> > > > > >
> > > > > > diff --git a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > > b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > > index 9cc1d678674f..c436a28d50e4 100644
> > > > > > --- a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > > +++ b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > > @@ -91,14 +91,14 @@ static void
> > > > > > ipu_crtc_atomic_disable(struct
> > > > > > drm_crtc *crtc,
> > > > > >       ipu_dc_disable(ipu);
> > > > > >       ipu_prg_disable(ipu);
> > > > > >
> > > > > > +     drm_crtc_vblank_off(crtc);
> > > > > > +
> > > > >
> > > > > This is explained in the commit message and aligns with the
> > > > > drm_crtc_state @event documentation.
> > > >
> > > > This part here looks fishy. The drm_vblank.c code is supposed to
> > > > do
> > > > the right thing, no matter where or when you ask it to generate
> > > > an
> > > > event. It definitely shouldn't generate a timestamp that's a few
> > > > seconds too early. Bunch of options:
> > > > - there's a bug in drm_vblank.c and it's mixing up something and
> > > > generating a totally bogus value.
> > > > - there's a lie in your imx vblank code, which trips the
> > > > drm_vblank.c
> > > > counter interpolation and results in a totally bogus value.
> > > >
> > > > drm_vblank.c assumes that if you do claim to have a hw counter
> > > > and
> > > > generate timestamps, that those are perfectly accurate. It only
> > > > falls
> > > > back to guestimating using the system timer if that's not
> > > > present.
> > > >
> > > > Either way, this very much smells like papering over a bug if
> > > > this
> > > > change indeed fixes your wrong vblank timestamps.
> > > >
> > >
> > > A quick explaination of where the dodgy timestamp came from:
> > > 1. driver starts up
> > > 2. fbcon comes along and restores fbdev, enabling vblank
> > > 3. vblank_disable_fn fires via timer disabling vblank, keeping
> > > vblank
> > > seq number and time set at current value
> > > (some time later)
> > > 4. weston starts and does a modeset
> > > 5. atomic commit disables crtc while it does the modeset
> > > 6. ipu_crtc_atomic_disable sends vblank with old seq number and
> > > time
> > >
> > > It turns out the actual fix for the old vblank is the next change,
> > > which stops it being sent at all during the crtc disable as it is
> > > is
> > > still active, it would then go through drm_crtc_vblank_off,
> > > reseting
> > > the timestamp, and get delivered during the vblank enable as part
> > > of
> > > the atomic commit.
> >
> > This shouldn't fix your vblank timestamp troubles either. It might
> > mean
> > that the timestamp is slightly too early (because you take it while
> > shutting down the crtc, not while re-enabling), but not by seconds.
> >
> > Quick experiment: Disable vblank disabling with drm.vblankoffdelay =
> > 0. If
> > that also fixes the timestamps, then I'm pretty sure you have a
> > driver bug
> > somewhere and lie to the vblank core code about something.
> > -Daniel
> >
>
> Experiment done. The timestamp is fine, it is the timestamp of the
> previous vblank update. But, this would fix it because the vblank
> interrupt was never disabled.
>
> The original issue was that the event got sent after vblank was
> disabled and before it got re-enabled during the modeset, so nothing
> had happened to update the timestamp and seq number.
>
> What are you expecting to update the timestamp and seq number while the
> interrupt is disabled after vblank_disable_fn?

Hm maybe this indeed needs to be shuffled around a bit, since
currently it's indeed not not allowed to call
drm_crtc_send_vblank_event if:
- your driver has vblank support (i.e. dev->num_crtcs > 0)
- the vblank irq is off (i.e. no one called drm_crtc_vblank_get)
- from the vblank code's pov the pipe is still running (i.e. not
in-between a drm_crtc_vblank_off()/on() pair)

If all of these conditions hold then drm_crtc_send_vblank_event is
going to give you a garbage timestamp and and sequence number. If you
call drm_crtc_vblank_get/put around it, or after vblank_off, then
either of those will have rolled things forward for you.

The other option I was chasing is a get_vblank_counter driver callback
which lies, but I think that's only relevant for immediate disabling
support.

Anyway, thanks for sticking with me on this. Can I volunteer you to
write a patch to improve the documentation of
drm_crtc_send_vblank_event, plus add a WARN_ON in there that fires if
the above conditions are all true? I expect imx isn't the only one
that gets this wrong, would be good to close this trap for real.

> Im struggling to see what this experiment was meant to test/prove.

Worked all fine in confirming what I wanted to confirm.

Thanks, Daniel

>
> > >
> > > So, in theory, we could just have the following change to fix the
> > > specific issue of a stale timestamp.
> > >
> > > However, given the documentation for the event in
> > > include/drm/drm_crtc.h:
> > >
> > >          *  - The event is for a CRTC which is being disabled
> > > through
> > > this
> > >          *    atomic commit. In that case the event can be send out
> > > any
> > > time
> > >          *    after the hardware has stopped scanning out the
> > > current
> > >          *    framebuffers. It should contain the timestamp and
> > > counter
> > > for the
> > >          *    last vblank before the display pipeline was shut off.
> > > The
> > > simplest
> > >          *    way to achieve that is calling
> > > drm_crtc_send_vblank_event()
> > >          *    somewhen after drm_crtc_vblank_off() has been called.
> > >
> > > This still seems like a sensible change for when the crtc is being
> > > disabled.
> > >
> > >
> > >
> > > > > >       spin_lock_irq(&crtc->dev->event_lock);
> > > > > > -     if (crtc->state->event)
> > > > > > {
> > > > > > +     if (crtc->state->event && !crtc->state->active) {
> > > > >
> > > > > This is not mentioned though.
> > > > >
> > > > > If the pending event is not sent here, I assume it will be
> > > > > picked
> > > > > up by
> > > > > .atomic_flush and will then be sent after the first EOF
> > > > > interrupt
> > > > > after
> > > > > the modeset is complete. Can you explain this in the commit
> > > > > message?
> > > >
> > > > Yeah looks correct (you only want to generate the event here when
> > > > the
> > > > crtc stays off), if it gets re-enabled the event should only be
> > > > generated later on once that's all finished. But separate bugfix.
> > > > -Daniel
> > > >
> > >
> > > It looks like this is actually the fix needed to avoid the bogus
> > > timestamp.
> > >
> > > I can split this patch up in to 2 commits if desired?
> > >
> > > > >
> > > > > With that,
> > > > > Reviewed-by: Philipp Zabel <p.zabel@pengutronix.de>
> > > > >
> > > > > >               drm_crtc_send_vblank_event(crtc, crtc->state-
> > > > > > > event);
> > > > > >
> > > > > >               crtc->state->event = NULL;
> > > > > >       }
> > > > > >       spin_unlock_irq(&crtc->dev->event_lock);
> > > > > > -
> > > > > > -     drm_crtc_vblank_off(crtc);
> > > > > >  }
> > > > > >
> > > > > >  static void imx_drm_crtc_reset(struct drm_crtc *crtc)
> > > > >
> > > > > regards
> > > > > Philipp
> > > > > _______________________________________________
> > > > > dri-devel mailing list
> > > > > dri-devel@lists.freedesktop.org
> > > > > https://lists.freedesktop.org/mailman/listinfo/dri-devel
> > > >
> > > >
> > > >
> >
> >
>


-- 
Daniel Vetter
Software Engineer, Intel Corporation
+41 (0) 79 365 57 48 - http://blog.ffwll.ch
_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH] drm/imx: correct order of crtc disable

[Robert Beckett]

On Thu, 2019-06-20 at 18:29 +0200, Daniel Vetter wrote:
> On Thu, Jun 20, 2019 at 3:30 PM Robert Beckett
> <bob.beckett@collabora.com> wrote:
> > On Thu, 2019-06-20 at 14:32 +0200, Daniel Vetter wrote:
> > > On Thu, Jun 20, 2019 at 12:12:13PM +0100, Robert Beckett wrote:
> > > > On Thu, 2019-06-20 at 10:50 +0200, Daniel Vetter wrote:
> > > > > On Wed, Jun 19, 2019 at 11:40 AM Philipp Zabel <
> > > > > p.zabel@pengutronix.de> wrote:
> > > > > > 
> > > > > > Hi Robert,
> > > > > > 
> > > > > > thank you for the patch.
> > > > > > 
> > > > > > On Tue, 2019-06-18 at 16:50 +0100, Robert Beckett wrote:
> > > > > > > Notify drm core before sending pending events during crtc
> > > > > > > disable.
> > > > > > > This fixes the first event after disable having an old
> > > > > > > stale
> > > > > > > timestamp
> > > > > > > by having drm_crtc_vblank_off update the timestamp to
> > > > > > > now.
> > > > > > > 
> > > > > > > This was seen while debugging weston log message:
> > > > > > > Warning: computed repaint delay is insane: -8212 msec
> > > > > > > 
> > > > > > 
> > > > > > Would you say this
> > > > > > Fixes: a474478642d5 ("drm/imx: fix crtc vblank state
> > > > > > regression")
> > > > > > ?
> > > > > > 
> > > > > > > Signed-off-by: Robert Beckett <bob.beckett@collabora.com>
> > > > > > > ---
> > > > > > >  drivers/gpu/drm/imx/ipuv3-crtc.c | 6 +++---
> > > > > > >  1 file changed, 3 insertions(+), 3 deletions(-)
> > > > > > > 
> > > > > > > diff --git a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > > > b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > > > index 9cc1d678674f..c436a28d50e4 100644
> > > > > > > --- a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > > > +++ b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > > > @@ -91,14 +91,14 @@ static void
> > > > > > > ipu_crtc_atomic_disable(struct
> > > > > > > drm_crtc *crtc,
> > > > > > >       ipu_dc_disable(ipu);
> > > > > > >       ipu_prg_disable(ipu);
> > > > > > > 
> > > > > > > +     drm_crtc_vblank_off(crtc);
> > > > > > > +
> > > > > > 
> > > > > > This is explained in the commit message and aligns with the
> > > > > > drm_crtc_state @event documentation.
> > > > > 
> > > > > This part here looks fishy. The drm_vblank.c code is supposed
> > > > > to
> > > > > do
> > > > > the right thing, no matter where or when you ask it to
> > > > > generate
> > > > > an
> > > > > event. It definitely shouldn't generate a timestamp that's a
> > > > > few
> > > > > seconds too early. Bunch of options:
> > > > > - there's a bug in drm_vblank.c and it's mixing up something
> > > > > and
> > > > > generating a totally bogus value.
> > > > > - there's a lie in your imx vblank code, which trips the
> > > > > drm_vblank.c
> > > > > counter interpolation and results in a totally bogus value.
> > > > > 
> > > > > drm_vblank.c assumes that if you do claim to have a hw
> > > > > counter
> > > > > and
> > > > > generate timestamps, that those are perfectly accurate. It
> > > > > only
> > > > > falls
> > > > > back to guestimating using the system timer if that's not
> > > > > present.
> > > > > 
> > > > > Either way, this very much smells like papering over a bug if
> > > > > this
> > > > > change indeed fixes your wrong vblank timestamps.
> > > > > 
> > > > 
> > > > A quick explaination of where the dodgy timestamp came from:
> > > > 1. driver starts up
> > > > 2. fbcon comes along and restores fbdev, enabling vblank
> > > > 3. vblank_disable_fn fires via timer disabling vblank, keeping
> > > > vblank
> > > > seq number and time set at current value
> > > > (some time later)
> > > > 4. weston starts and does a modeset
> > > > 5. atomic commit disables crtc while it does the modeset
> > > > 6. ipu_crtc_atomic_disable sends vblank with old seq number and
> > > > time
> > > > 
> > > > It turns out the actual fix for the old vblank is the next
> > > > change,
> > > > which stops it being sent at all during the crtc disable as it
> > > > is
> > > > is
> > > > still active, it would then go through drm_crtc_vblank_off,
> > > > reseting
> > > > the timestamp, and get delivered during the vblank enable as
> > > > part
> > > > of
> > > > the atomic commit.
> > > 
> > > This shouldn't fix your vblank timestamp troubles either. It
> > > might
> > > mean
> > > that the timestamp is slightly too early (because you take it
> > > while
> > > shutting down the crtc, not while re-enabling), but not by
> > > seconds.
> > > 
> > > Quick experiment: Disable vblank disabling with
> > > drm.vblankoffdelay =
> > > 0. If
> > > that also fixes the timestamps, then I'm pretty sure you have a
> > > driver bug
> > > somewhere and lie to the vblank core code about something.
> > > -Daniel
> > > 
> > 
> > Experiment done. The timestamp is fine, it is the timestamp of the
> > previous vblank update. But, this would fix it because the vblank
> > interrupt was never disabled.
> > 
> > The original issue was that the event got sent after vblank was
> > disabled and before it got re-enabled during the modeset, so
> > nothing
> > had happened to update the timestamp and seq number.
> > 
> > What are you expecting to update the timestamp and seq number while
> > the
> > interrupt is disabled after vblank_disable_fn?
> 
> Hm maybe this indeed needs to be shuffled around a bit, since
> currently it's indeed not not allowed to call
> drm_crtc_send_vblank_event if:
> - your driver has vblank support (i.e. dev->num_crtcs > 0)
> - the vblank irq is off (i.e. no one called drm_crtc_vblank_get)
> - from the vblank code's pov the pipe is still running (i.e. not
> in-between a drm_crtc_vblank_off()/on() pair)
> 
> If all of these conditions hold then drm_crtc_send_vblank_event is
> going to give you a garbage timestamp and and sequence number. If you
> call drm_crtc_vblank_get/put around it, or after vblank_off, then
> either of those will have rolled things forward for you.
> 
> The other option I was chasing is a get_vblank_counter driver
> callback
> which lies, but I think that's only relevant for immediate disabling
> support.
> 
> Anyway, thanks for sticking with me on this. Can I volunteer you to
> write a patch to improve the documentation of
> drm_crtc_send_vblank_event, plus add a WARN_ON in there that fires if
> the above conditions are all true? I expect imx isn't the only one
> that gets this wrong, would be good to close this trap for real.

Sure, Ill add it as part of v3 once Ive figured out which combination
of state I can use for the WARN_ON, along with the split up of this
patch in to 2 separate patches. (Tomorrow)

> 
> > Im struggling to see what this experiment was meant to test/prove.
> 
> Worked all fine in confirming what I wanted to confirm.
> 
> Thanks, Daniel

No problem. Thanks for the due diligence.

> 
> > 
> > > > 
> > > > So, in theory, we could just have the following change to fix
> > > > the
> > > > specific issue of a stale timestamp.
> > > > 
> > > > However, given the documentation for the event in
> > > > include/drm/drm_crtc.h:
> > > > 
> > > >          *  - The event is for a CRTC which is being disabled
> > > > through
> > > > this
> > > >          *    atomic commit. In that case the event can be send
> > > > out
> > > > any
> > > > time
> > > >          *    after the hardware has stopped scanning out the
> > > > current
> > > >          *    framebuffers. It should contain the timestamp and
> > > > counter
> > > > for the
> > > >          *    last vblank before the display pipeline was shut
> > > > off.
> > > > The
> > > > simplest
> > > >          *    way to achieve that is calling
> > > > drm_crtc_send_vblank_event()
> > > >          *    somewhen after drm_crtc_vblank_off() has been
> > > > called.
> > > > 
> > > > This still seems like a sensible change for when the crtc is
> > > > being
> > > > disabled.
> > > > 
> > > > 
> > > > 
> > > > > > >       spin_lock_irq(&crtc->dev->event_lock);
> > > > > > > -     if (crtc->state->event)
> > > > > > > {
> > > > > > > +     if (crtc->state->event && !crtc->state->active) {
> > > > > > 
> > > > > > This is not mentioned though.
> > > > > > 
> > > > > > If the pending event is not sent here, I assume it will be
> > > > > > picked
> > > > > > up by
> > > > > > .atomic_flush and will then be sent after the first EOF
> > > > > > interrupt
> > > > > > after
> > > > > > the modeset is complete. Can you explain this in the commit
> > > > > > message?
> > > > > 
> > > > > Yeah looks correct (you only want to generate the event here
> > > > > when
> > > > > the
> > > > > crtc stays off), if it gets re-enabled the event should only
> > > > > be
> > > > > generated later on once that's all finished. But separate
> > > > > bugfix.
> > > > > -Daniel
> > > > > 
> > > > 
> > > > It looks like this is actually the fix needed to avoid the
> > > > bogus
> > > > timestamp.
> > > > 
> > > > I can split this patch up in to 2 commits if desired?
> > > > 
> > > > > > 
> > > > > > With that,
> > > > > > Reviewed-by: Philipp Zabel <p.zabel@pengutronix.de>
> > > > > > 
> > > > > > >               drm_crtc_send_vblank_event(crtc, crtc-
> > > > > > > >state-
> > > > > > > > event);
> > > > > > > 
> > > > > > >               crtc->state->event = NULL;
> > > > > > >       }
> > > > > > >       spin_unlock_irq(&crtc->dev->event_lock);
> > > > > > > -
> > > > > > > -     drm_crtc_vblank_off(crtc);
> > > > > > >  }
> > > > > > > 
> > > > > > >  static void imx_drm_crtc_reset(struct drm_crtc *crtc)
> > > > > > 
> > > > > > regards
> > > > > > Philipp
> > > > > > _______________________________________________
> > > > > > dri-devel mailing list
> > > > > > dri-devel@lists.freedesktop.org
> > > > > > https://lists.freedesktop.org/mailman/listinfo/dri-devel
> > > > > 
> > > > > 
> > > > > 
> > > 
> > > 
> 
> 

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH] drm/imx: correct order of crtc disable

[Robert Beckett]

On Thu, 2019-06-20 at 17:53 +0100, Robert Beckett wrote:
> On Thu, 2019-06-20 at 18:29 +0200, Daniel Vetter wrote:
> > On Thu, Jun 20, 2019 at 3:30 PM Robert Beckett
> > <bob.beckett@collabora.com> wrote:
> > > On Thu, 2019-06-20 at 14:32 +0200, Daniel Vetter wrote:
> > > > On Thu, Jun 20, 2019 at 12:12:13PM +0100, Robert Beckett wrote:
> > > > > On Thu, 2019-06-20 at 10:50 +0200, Daniel Vetter wrote:
> > > > > > On Wed, Jun 19, 2019 at 11:40 AM Philipp Zabel <
> > > > > > p.zabel@pengutronix.de> wrote:
> > > > > > > 
> > > > > > > Hi Robert,
> > > > > > > 
> > > > > > > thank you for the patch.
> > > > > > > 
> > > > > > > On Tue, 2019-06-18 at 16:50 +0100, Robert Beckett wrote:
> > > > > > > > Notify drm core before sending pending events during
> > > > > > > > crtc
> > > > > > > > disable.
> > > > > > > > This fixes the first event after disable having an old
> > > > > > > > stale
> > > > > > > > timestamp
> > > > > > > > by having drm_crtc_vblank_off update the timestamp to
> > > > > > > > now.
> > > > > > > > 
> > > > > > > > This was seen while debugging weston log message:
> > > > > > > > Warning: computed repaint delay is insane: -8212 msec
> > > > > > > > 
> > > > > > > 
> > > > > > > Would you say this
> > > > > > > Fixes: a474478642d5 ("drm/imx: fix crtc vblank state
> > > > > > > regression")
> > > > > > > ?
> > > > > > > 
> > > > > > > > Signed-off-by: Robert Beckett <
> > > > > > > > bob.beckett@collabora.com>
> > > > > > > > ---
> > > > > > > >  drivers/gpu/drm/imx/ipuv3-crtc.c | 6 +++---
> > > > > > > >  1 file changed, 3 insertions(+), 3 deletions(-)
> > > > > > > > 
> > > > > > > > diff --git a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > > > > b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > > > > index 9cc1d678674f..c436a28d50e4 100644
> > > > > > > > --- a/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > > > > +++ b/drivers/gpu/drm/imx/ipuv3-crtc.c
> > > > > > > > @@ -91,14 +91,14 @@ static void
> > > > > > > > ipu_crtc_atomic_disable(struct
> > > > > > > > drm_crtc *crtc,
> > > > > > > >       ipu_dc_disable(ipu);
> > > > > > > >       ipu_prg_disable(ipu);
> > > > > > > > 
> > > > > > > > +     drm_crtc_vblank_off(crtc);
> > > > > > > > +
> > > > > > > 
> > > > > > > This is explained in the commit message and aligns with
> > > > > > > the
> > > > > > > drm_crtc_state @event documentation.
> > > > > > 
> > > > > > This part here looks fishy. The drm_vblank.c code is
> > > > > > supposed
> > > > > > to
> > > > > > do
> > > > > > the right thing, no matter where or when you ask it to
> > > > > > generate
> > > > > > an
> > > > > > event. It definitely shouldn't generate a timestamp that's
> > > > > > a
> > > > > > few
> > > > > > seconds too early. Bunch of options:
> > > > > > - there's a bug in drm_vblank.c and it's mixing up
> > > > > > something
> > > > > > and
> > > > > > generating a totally bogus value.
> > > > > > - there's a lie in your imx vblank code, which trips the
> > > > > > drm_vblank.c
> > > > > > counter interpolation and results in a totally bogus value.
> > > > > > 
> > > > > > drm_vblank.c assumes that if you do claim to have a hw
> > > > > > counter
> > > > > > and
> > > > > > generate timestamps, that those are perfectly accurate. It
> > > > > > only
> > > > > > falls
> > > > > > back to guestimating using the system timer if that's not
> > > > > > present.
> > > > > > 
> > > > > > Either way, this very much smells like papering over a bug
> > > > > > if
> > > > > > this
> > > > > > change indeed fixes your wrong vblank timestamps.
> > > > > > 
> > > > > 
> > > > > A quick explaination of where the dodgy timestamp came from:
> > > > > 1. driver starts up
> > > > > 2. fbcon comes along and restores fbdev, enabling vblank
> > > > > 3. vblank_disable_fn fires via timer disabling vblank,
> > > > > keeping
> > > > > vblank
> > > > > seq number and time set at current value
> > > > > (some time later)
> > > > > 4. weston starts and does a modeset
> > > > > 5. atomic commit disables crtc while it does the modeset
> > > > > 6. ipu_crtc_atomic_disable sends vblank with old seq number
> > > > > and
> > > > > time
> > > > > 
> > > > > It turns out the actual fix for the old vblank is the next
> > > > > change,
> > > > > which stops it being sent at all during the crtc disable as
> > > > > it
> > > > > is
> > > > > is
> > > > > still active, it would then go through drm_crtc_vblank_off,
> > > > > reseting
> > > > > the timestamp, and get delivered during the vblank enable as
> > > > > part
> > > > > of
> > > > > the atomic commit.
> > > > 
> > > > This shouldn't fix your vblank timestamp troubles either. It
> > > > might
> > > > mean
> > > > that the timestamp is slightly too early (because you take it
> > > > while
> > > > shutting down the crtc, not while re-enabling), but not by
> > > > seconds.
> > > > 
> > > > Quick experiment: Disable vblank disabling with
> > > > drm.vblankoffdelay =
> > > > 0. If
> > > > that also fixes the timestamps, then I'm pretty sure you have a
> > > > driver bug
> > > > somewhere and lie to the vblank core code about something.
> > > > -Daniel
> > > > 
> > > 
> > > Experiment done. The timestamp is fine, it is the timestamp of
> > > the
> > > previous vblank update. But, this would fix it because the vblank
> > > interrupt was never disabled.
> > > 
> > > The original issue was that the event got sent after vblank was
> > > disabled and before it got re-enabled during the modeset, so
> > > nothing
> > > had happened to update the timestamp and seq number.
> > > 
> > > What are you expecting to update the timestamp and seq number
> > > while
> > > the
> > > interrupt is disabled after vblank_disable_fn?
> > 
> > Hm maybe this indeed needs to be shuffled around a bit, since
> > currently it's indeed not not allowed to call
> > drm_crtc_send_vblank_event if:
> > - your driver has vblank support (i.e. dev->num_crtcs > 0)
> > - the vblank irq is off (i.e. no one called drm_crtc_vblank_get)
> > - from the vblank code's pov the pipe is still running (i.e. not
> > in-between a drm_crtc_vblank_off()/on() pair)
> > 
> > If all of these conditions hold then drm_crtc_send_vblank_event is
> > going to give you a garbage timestamp and and sequence number. If
> > you
> > call drm_crtc_vblank_get/put around it, or after vblank_off, then
> > either of those will have rolled things forward for you.
> > 
> > The other option I was chasing is a get_vblank_counter driver
> > callback
> > which lies, but I think that's only relevant for immediate
> > disabling
> > support.
> > 
> > Anyway, thanks for sticking with me on this. Can I volunteer you to
> > write a patch to improve the documentation of
> > drm_crtc_send_vblank_event, plus add a WARN_ON in there that fires
> > if
> > the above conditions are all true? I expect imx isn't the only one
> > that gets this wrong, would be good to close this trap for real.

It turns out it is not as simple as calling drm_crtc_vblank_off() to
update the timestamp and seq number before sending the event.
drm_crtc_vblank_off() calls drm_vblank_disable_and_save() to update the
info, but that doesnt actually do the update if !vblank->enabled for
the legit reason that the driver may have runtime disabled the
timestamp register HW.

In the situation where interrupts were disabled long ago, and the
modeset is disabling the crtc, we would want an up to date timestamp
and seq number for signalling the disable of a crtc, but cant get the
updated values if interrupts were previously disabled.

Im not sure how to handle this case generically.
We could just set the timestamp to now, but what to do about the seq
number? Increment it? keep it the same?

Any thoughts on this?

For the similar case where the crtc is being enabled during the modeset
with vblank enabled, the later fix of checking for !crtc->state->active 
before sending the event still works as it will be delivered during
next vblank with an updated stamp.


> 
> Sure, Ill add it as part of v3 once Ive figured out which combination
> of state I can use for the WARN_ON, along with the split up of this
> patch in to 2 separate patches. (Tomorrow)
> 
> > 
> > > Im struggling to see what this experiment was meant to
> > > test/prove.
> > 
> > Worked all fine in confirming what I wanted to confirm.
> > 
> > Thanks, Daniel
> 
> No problem. Thanks for the due diligence.
> 
> > 
> > > 
> > > > > 
> > > > > So, in theory, we could just have the following change to fix
> > > > > the
> > > > > specific issue of a stale timestamp.
> > > > > 
> > > > > However, given the documentation for the event in
> > > > > include/drm/drm_crtc.h:
> > > > > 
> > > > >          *  - The event is for a CRTC which is being disabled
> > > > > through
> > > > > this
> > > > >          *    atomic commit. In that case the event can be
> > > > > send
> > > > > out
> > > > > any
> > > > > time
> > > > >          *    after the hardware has stopped scanning out the
> > > > > current
> > > > >          *    framebuffers. It should contain the timestamp
> > > > > and
> > > > > counter
> > > > > for the
> > > > >          *    last vblank before the display pipeline was
> > > > > shut
> > > > > off.
> > > > > The
> > > > > simplest
> > > > >          *    way to achieve that is calling
> > > > > drm_crtc_send_vblank_event()
> > > > >          *    somewhen after drm_crtc_vblank_off() has been
> > > > > called.
> > > > > 
> > > > > This still seems like a sensible change for when the crtc is
> > > > > being
> > > > > disabled.
> > > > > 
> > > > > 
> > > > > 
> > > > > > > >       spin_lock_irq(&crtc->dev->event_lock);
> > > > > > > > -     if (crtc->state->event)
> > > > > > > > {
> > > > > > > > +     if (crtc->state->event && !crtc->state->active) {
> > > > > > > 
> > > > > > > This is not mentioned though.
> > > > > > > 
> > > > > > > If the pending event is not sent here, I assume it will
> > > > > > > be
> > > > > > > picked
> > > > > > > up by
> > > > > > > .atomic_flush and will then be sent after the first EOF
> > > > > > > interrupt
> > > > > > > after
> > > > > > > the modeset is complete. Can you explain this in the
> > > > > > > commit
> > > > > > > message?
> > > > > > 
> > > > > > Yeah looks correct (you only want to generate the event
> > > > > > here
> > > > > > when
> > > > > > the
> > > > > > crtc stays off), if it gets re-enabled the event should
> > > > > > only
> > > > > > be
> > > > > > generated later on once that's all finished. But separate
> > > > > > bugfix.
> > > > > > -Daniel
> > > > > > 
> > > > > 
> > > > > It looks like this is actually the fix needed to avoid the
> > > > > bogus
> > > > > timestamp.
> > > > > 
> > > > > I can split this patch up in to 2 commits if desired?
> > > > > 
> > > > > > > 
> > > > > > > With that,
> > > > > > > Reviewed-by: Philipp Zabel <p.zabel@pengutronix.de>
> > > > > > > 
> > > > > > > >               drm_crtc_send_vblank_event(crtc, crtc-
> > > > > > > > > state-
> > > > > > > > > event);
> > > > > > > > 
> > > > > > > >               crtc->state->event = NULL;
> > > > > > > >       }
> > > > > > > >       spin_unlock_irq(&crtc->dev->event_lock);
> > > > > > > > -
> > > > > > > > -     drm_crtc_vblank_off(crtc);
> > > > > > > >  }
> > > > > > > > 
> > > > > > > >  static void imx_drm_crtc_reset(struct drm_crtc *crtc)
> > > > > > > 
> > > > > > > regards
> > > > > > > Philipp
> > > > > > > _______________________________________________
> > > > > > > dri-devel mailing list
> > > > > > > dri-devel@lists.freedesktop.org
> > > > > > > https://lists.freedesktop.org/mailman/listinfo/dri-devel
> > > > > > 
> > > > > > 
> > > > > > 
> > > > 
> > > > 
> > 
> > 
> 
> _______________________________________________
> dri-devel mailing list
> dri-devel@lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/dri-devel

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel