On Fri, Apr 08, 2022 at 06:59:07PM +0300, Ville Syrjälä wrote:
> On Fri, Apr 08, 2022 at 06:46:00PM +0300, Ville Syrjälä wrote:
> > On Fri, Apr 08, 2022 at 03:51:59PM +0300, Stanislav Lisovskiy wrote:
> > > Currently skl_pcode_try_request function doesn't
> > > properly handle return value it gets from
> > > snb_pcode_rw, but treats status != 0 as success,
> > > returning true, which basically doesn't allow
> > > to use retry/timeout mechanisms if PCode happens
> > > to be busy and returns EGAIN or some other status
> > > code not equal to 0.
> > >
> > > We saw this on real hw and also tried simulating this
> > > by always returning -EAGAIN from snb_pcode_rw for 6 times, which
> > > currently will just result in false success, while it should
> > > have tried until timeout is reached:
> > >
> > > [ 22.357729] i915 0000:00:02.0: [drm:intel_cdclk_dump_config [i915]] Changing CDCLK to
> > > 307200 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
> > > [ 22.357831] i915 0000:00:02.0: [drm:__snb_pcode_rw [i915]] Returning EAGAIN retry 1
> > > [ 22.357892] i915 0000:00:02.0: [drm:skl_pcode_request [i915]] Success, exiting
> > > [ 22.357936] i915 0000:00:02.0: [drm] ERROR Failed to inform PCU about cdclk change (err -11, freq 307200)
> > >
> > > We see en error because higher level api, still notices that status was wrong,
> > > however we still did try only once.
> > >
> > > We fix it by requiring _both_ the status to be 0 and
> > > request/reply match for success(true) and function
> > > should return failure(false) if either status turns
> > > out to be EAGAIN, EBUSY or whatever or reply/request
> > > masks do not match.
> > >
> > > So now we see this in the logs:
> > >
> > > [ 22.318667] i915 0000:00:02.0: [drm:intel_cdclk_dump_config [i915]] Changing CDCLK to
> > > 307200 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
> > > [ 22.318782] i915 0000:00:02.0: [drm:__snb_pcode_rw [i915]] Returning EAGAIN retry 1
>
> Hmm. That is weird. The timestamp difference is only ~100 usec even
> though we are supposed to use that 500 usec timeout. So did some
> previous pcode access already timeout and leave the mailbox busy
> before we even do this request, or what is going on?
Ah that is not the real example.
What I did to check how it works is just added something like this:
+ static int retries = 0;
+ if (++retry < 6)
+ return -EAGAIN
to _snb_pcode_rw.
So before the patch, skl_pcode_try_request returned True when getting -EAGAIN and
immediately bailed out, assigning ret = 0 and goto out, as if it succeeded while it obvously not.
>
> > > [ 22.318849] i915 0000:00:02.0: [drm:__snb_pcode_rw [i915]] Returning EAGAIN retry 2
> > > [ 22.319006] i915 0000:00:02.0: [drm:__snb_pcode_rw [i915]] Returning EAGAIN retry 3
> > > [ 22.319091] i915 0000:00:02.0: [drm:__snb_pcode_rw [i915]] Returning EAGAIN retry 4
> > > [ 22.319158] i915 0000:00:02.0: [drm:__snb_pcode_rw [i915]] Returning EAGAIN retry 5
> > > [ 22.319224] i915 0000:00:02.0: [drm:__snb_pcode_rw [i915]] Returning EAGAIN retry 6
That is how it behaves with this patch, i.e status != 0 makes skl_pcode_try_request
return False(as it should) which then enables skl_pcode_request retry machinery.
In real case we have something similar to this but can't really reproduce it that easily,
so was kinda simulating that issue to check.
Stan
> > >
> > > Reviewed-by: Vinod Govindapillai <vinod.govindapillai@xxxxxxxxx>
> > > Signed-off-by: Stanislav Lisovskiy <stanislav.lisovskiy@xxxxxxxxx>
> > > ---
> > > drivers/gpu/drm/i915/intel_pcode.c | 2 +-
> > > 1 file changed, 1 insertion(+), 1 deletion(-)
> > >
> > > diff --git a/drivers/gpu/drm/i915/intel_pcode.c b/drivers/gpu/drm/i915/intel_pcode.c
> > > index 391a37492ce5..fb6c43e8a02f 100644
> > > --- a/drivers/gpu/drm/i915/intel_pcode.c
> > > +++ b/drivers/gpu/drm/i915/intel_pcode.c
> > > @@ -136,7 +136,7 @@ static bool skl_pcode_try_request(struct drm_i915_private *i915, u32 mbox,
> > > {
> > > *status = __snb_pcode_rw(i915, mbox, &request, NULL, 500, 0, true);
> > >
> > > - return *status || ((request & reply_mask) == reply);
> > > + return (*status == 0) && ((request & reply_mask) == reply);
> >
> > The problem with this is that now we'll keep pointlessly banging it
> > even if it returns a real error.
> >
> > We should never really see that -EAGAIN since it indicates that our
> > timeout is too short. So the real fix should be to increase that
> > timeout. But I guess we could do a belt-and-suspenders approach
> > where we also keep repeating on -EGAIN. But I'm thinking -EAGAIN
> > should WARN as well to make sure we notice that our timeout is wrong.
> >
> > > }
> > >
> > > /**
> > > --
> > > 2.24.1.485.gad05a3d8e5
> >
> > --
> > Ville Syrjälä
> > Intel
>
> --
> Ville Syrjälä
> Intel
