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

[Robert Beckett <bob.beckett@collabora.com>]

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