| Message ID | 20210811180844.2130484-1-markyacoub@chromium.org |
|---|---|
| State | New |
| Headers | show |
| Series | drm/msm: Read frame_count and line_count even when disabled. | expand |
On Wed, Aug 11, 2021 at 11:12 AM Mark Yacoub <markyacoub@chromium.org> wrote: > > From: Mark Yacoub <markyacoub@google.com> > > [why] > Reading frame count register used to get the vblank counter, which calls > dpu_encoder_phys to get the frame count. Even when it's disabled, the > vblank counter (through frame count) should return a valid value for the > count. An invalid value of 0, when compared to vblank->last (in > drm_vblank.c::drm_update_vblank_count()) returns an invalid number that > throws off the vblank counter for the lifetime of the process. > > Rationale: > In drm_vblank.c::drm_update_vblank_count(), the new diff is calculated > through: > diff = (cur_vblank - vblank->last) & max_vblank_count; > cur_vblank comes from: cur_vblank = __get_vblank_counter(dev, pipe); > When the value is 0, diff results in a negative number (a very large > number as it's unsigned), which inflates the vblank count when the diff > is added to the current vblank->count. > > [How] > Read frame_count register whether interface timing engine is enabled or > not. > > Fixes: IGT:kms_flip::modeset-vs-vblank-race-interruptible > Tested on ChromeOS Trogdor(msm) > > Signed-off-by: Mark Yacoub <markyacoub@chromium.org> Reviewed-by: Rob Clark <robdclark@chromium.org> But I suspect we may have a bit more work for the display-off case.. or at least I'm not seeing anything obviously doing a pm_runtime_get() in this call path. I'm also not sure if the line/frame-count registers loose state across a suspend->resume cycle, it might be that we need to save/restore these registers in the suspend/resume path? Abhinav? BR, -R > --- > drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c | 9 ++------- > drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h | 2 +- > 2 files changed, 3 insertions(+), 8 deletions(-) > > diff --git a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c > index 116e2b5b1a90f..c436d901629f3 100644 > --- a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c > +++ b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c > @@ -266,13 +266,8 @@ static void dpu_hw_intf_get_status( > > s->is_en = DPU_REG_READ(c, INTF_TIMING_ENGINE_EN); > s->is_prog_fetch_en = !!(DPU_REG_READ(c, INTF_CONFIG) & BIT(31)); > - if (s->is_en) { > - s->frame_count = DPU_REG_READ(c, INTF_FRAME_COUNT); > - s->line_count = DPU_REG_READ(c, INTF_LINE_COUNT); > - } else { > - s->line_count = 0; > - s->frame_count = 0; > - } > + s->frame_count = DPU_REG_READ(c, INTF_FRAME_COUNT); > + s->line_count = DPU_REG_READ(c, INTF_LINE_COUNT); > } > > static u32 dpu_hw_intf_get_line_count(struct dpu_hw_intf *intf) > diff --git a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h > index 3568be80dab51..877ff48bfef04 100644 > --- a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h > +++ b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h > @@ -41,7 +41,7 @@ struct intf_prog_fetch { > struct intf_status { > u8 is_en; /* interface timing engine is enabled or not */ > u8 is_prog_fetch_en; /* interface prog fetch counter is enabled or not */ > - u32 frame_count; /* frame count since timing engine enabled */ > + u32 frame_count; /* frame count since timing engine first enabled */ > u32 line_count; /* current line count including blanking */ > }; > > -- > 2.33.0.rc1.237.g0d66db33f3-goog >
On Wed, Aug 11, 2021 at 4:11 PM <abhinavk@codeaurora.org> wrote: > > On 2021-08-11 11:43, Rob Clark wrote: > > On Wed, Aug 11, 2021 at 11:12 AM Mark Yacoub <markyacoub@chromium.org> > > wrote: > >> > >> From: Mark Yacoub <markyacoub@google.com> > >> > >> [why] > >> Reading frame count register used to get the vblank counter, which > >> calls > >> dpu_encoder_phys to get the frame count. Even when it's disabled, the > >> vblank counter (through frame count) should return a valid value for > >> the > >> count. An invalid value of 0, when compared to vblank->last (in > >> drm_vblank.c::drm_update_vblank_count()) returns an invalid number > >> that > >> throws off the vblank counter for the lifetime of the process. > >> > >> Rationale: > >> In drm_vblank.c::drm_update_vblank_count(), the new diff is calculated > >> through: > >> diff = (cur_vblank - vblank->last) & max_vblank_count; > >> cur_vblank comes from: cur_vblank = __get_vblank_counter(dev, pipe); > >> When the value is 0, diff results in a negative number (a very large > >> number as it's unsigned), which inflates the vblank count when the > >> diff > >> is added to the current vblank->count. > >> > >> [How] > >> Read frame_count register whether interface timing engine is enabled > >> or > >> not. > >> > >> Fixes: IGT:kms_flip::modeset-vs-vblank-race-interruptible > >> Tested on ChromeOS Trogdor(msm) > >> > >> Signed-off-by: Mark Yacoub <markyacoub@chromium.org> > > > > Reviewed-by: Rob Clark <robdclark@chromium.org> > > > > But I suspect we may have a bit more work for the display-off case.. > > or at least I'm not seeing anything obviously doing a pm_runtime_get() > > in this call path. > > > > I'm also not sure if the line/frame-count registers loose state across > > a suspend->resume cycle, it might be that we need to save/restore > > these registers in the suspend/resume path? Abhinav? > > > > BR, > > -R > > > I spent sometime checking this and I dont think we should go ahead with > this change. > So when the timing engine is off, I believe the reason this works is > that the clocks are still not OFF yet > so this should be returning the last value of the vsync counter before > the timing engine was turned OFF. > If the clocks got turned OFF and there is a power collapse, I expect the > frame_count and line_count to get reset > to 0. I think if the interface clocks are off, it will be worse.. reading any register will make things go *boom*, won't it? That said, I don't think this patch is making that particular issue worse. > > I was also looking at the stack in which this error will start > happening. So I believe the sequence is like this > (mark can correct me if wrong): > > drm_crtc_vblank_off(crtc); ---> drm_vblank_disable_and_save ----> > drm_update_vblank_count ----> __get_vblank_counter(). > > crtc is disabled after the encoder so this path triggers an incorrect > value because encoder was already disabled (hence timing > engine was too). Clocks were still ON as full suspend hasnt happened > yet. > > To fix this, I think we should do what the downstream drivers did, so > something like this: > > 5471 static u32 dpu_crtc_get_vblank_counter(struct drm_crtc *crtc) > 5472 { > 5473 struct drm_encoder *encoder; > struct dpu_encoder_virt *dpu_enc = NULL; > > dpu_enc = to_dpu_encoder_virt(drm_enc); > 5480 > *********************************************************** > 5485 return dpu_encoder_get_frame_count(encoder); > ************************************************************ > > this just returns phys->vsync_cnt (which is just an atomic counter which > doesnt reset during disable) > So in other words instead of relying on the hw register value which can > be unpredictable when the timing engine is off, > use a sw counter I don't think that a sw counter will do the job, unless we never disable the vblank irq (or I am misunderstanding you).. the frame counter is expected to keep incrementing regardless of whether vblank is enabled or not. But it does sound like on suspend we need to store the current frame count, and add that offset later when asked for the current frame counter. BR, -R > 5486 } > 5487 > 5488 return 0; > 5489 } > > > >> --- > >> drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c | 9 ++------- > >> drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h | 2 +- > >> 2 files changed, 3 insertions(+), 8 deletions(-) > >> > >> diff --git a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c > >> b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c > >> index 116e2b5b1a90f..c436d901629f3 100644 > >> --- a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c > >> +++ b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c > >> @@ -266,13 +266,8 @@ static void dpu_hw_intf_get_status( > >> > >> s->is_en = DPU_REG_READ(c, INTF_TIMING_ENGINE_EN); > >> s->is_prog_fetch_en = !!(DPU_REG_READ(c, INTF_CONFIG) & > >> BIT(31)); > >> - if (s->is_en) { > >> - s->frame_count = DPU_REG_READ(c, INTF_FRAME_COUNT); > >> - s->line_count = DPU_REG_READ(c, INTF_LINE_COUNT); > >> - } else { > >> - s->line_count = 0; > >> - s->frame_count = 0; > >> - } > >> + s->frame_count = DPU_REG_READ(c, INTF_FRAME_COUNT); > >> + s->line_count = DPU_REG_READ(c, INTF_LINE_COUNT); > >> } > >> > >> static u32 dpu_hw_intf_get_line_count(struct dpu_hw_intf *intf) > >> diff --git a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h > >> b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h > >> index 3568be80dab51..877ff48bfef04 100644 > >> --- a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h > >> +++ b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h > >> @@ -41,7 +41,7 @@ struct intf_prog_fetch { > >> struct intf_status { > >> u8 is_en; /* interface timing engine is enabled > >> or not */ > >> u8 is_prog_fetch_en; /* interface prog fetch counter is > >> enabled or not */ > >> - u32 frame_count; /* frame count since timing engine > >> enabled */ > >> + u32 frame_count; /* frame count since timing engine first > >> enabled */ > >> u32 line_count; /* current line count including > >> blanking */ > >> }; > >> > >> -- > >> 2.33.0.rc1.237.g0d66db33f3-goog > >>
On Wed, Aug 11, 2021 at 7:37 PM <abhinavk@codeaurora.org> wrote: > > On 2021-08-11 16:28, Rob Clark wrote: > > On Wed, Aug 11, 2021 at 4:11 PM <abhinavk@codeaurora.org> wrote: > >> > >> On 2021-08-11 11:43, Rob Clark wrote: > >> > On Wed, Aug 11, 2021 at 11:12 AM Mark Yacoub <markyacoub@chromium.org> > >> > wrote: > >> >> > >> >> From: Mark Yacoub <markyacoub@google.com> > >> >> > >> >> [why] > >> >> Reading frame count register used to get the vblank counter, which > >> >> calls > >> >> dpu_encoder_phys to get the frame count. Even when it's disabled, the > >> >> vblank counter (through frame count) should return a valid value for > >> >> the > >> >> count. An invalid value of 0, when compared to vblank->last (in > >> >> drm_vblank.c::drm_update_vblank_count()) returns an invalid number > >> >> that > >> >> throws off the vblank counter for the lifetime of the process. > >> >> > >> >> Rationale: > >> >> In drm_vblank.c::drm_update_vblank_count(), the new diff is calculated > >> >> through: > >> >> diff = (cur_vblank - vblank->last) & max_vblank_count; > >> >> cur_vblank comes from: cur_vblank = __get_vblank_counter(dev, pipe); > >> >> When the value is 0, diff results in a negative number (a very large > >> >> number as it's unsigned), which inflates the vblank count when the > >> >> diff > >> >> is added to the current vblank->count. > >> >> > >> >> [How] > >> >> Read frame_count register whether interface timing engine is enabled > >> >> or > >> >> not. > >> >> > >> >> Fixes: IGT:kms_flip::modeset-vs-vblank-race-interruptible > >> >> Tested on ChromeOS Trogdor(msm) > >> >> > >> >> Signed-off-by: Mark Yacoub <markyacoub@chromium.org> > >> > > >> > Reviewed-by: Rob Clark <robdclark@chromium.org> > >> > > >> > But I suspect we may have a bit more work for the display-off case.. > >> > or at least I'm not seeing anything obviously doing a pm_runtime_get() > >> > in this call path. > >> > > >> > I'm also not sure if the line/frame-count registers loose state across > >> > a suspend->resume cycle, it might be that we need to save/restore > >> > these registers in the suspend/resume path? Abhinav? > >> > > >> > BR, > >> > -R > >> > > >> I spent sometime checking this and I dont think we should go ahead > >> with > >> this change. > >> So when the timing engine is off, I believe the reason this works is > >> that the clocks are still not OFF yet > >> so this should be returning the last value of the vsync counter before > >> the timing engine was turned OFF. > >> If the clocks got turned OFF and there is a power collapse, I expect > >> the > >> frame_count and line_count to get reset > >> to 0. > > > > I think if the interface clocks are off, it will be worse.. reading > > any register will make things go *boom*, won't it? > > > > That said, I don't think this patch is making that particular issue > > worse. > > Yes any unclocked access will cause an abort. What I am trying to > emphasize here > is that returning the register value after timing engine is off is > unreliable and should > not be done. Its working because even though timing engine is off, the > clocks are not > yet, so it returns the last value. But we should not rely on it because > its incorrect > to check these registers after timing engine off. > > > > >> > >> I was also looking at the stack in which this error will start > >> happening. So I believe the sequence is like this > >> (mark can correct me if wrong): > >> > >> drm_crtc_vblank_off(crtc); ---> drm_vblank_disable_and_save ----> > >> drm_update_vblank_count ----> __get_vblank_counter(). > >> > >> crtc is disabled after the encoder so this path triggers an incorrect > >> value because encoder was already disabled (hence timing > >> engine was too). Clocks were still ON as full suspend hasnt happened > >> yet. > >> > >> To fix this, I think we should do what the downstream drivers did, so > >> something like this: > >> > >> 5471 static u32 dpu_crtc_get_vblank_counter(struct drm_crtc *crtc) > >> 5472 { > >> 5473 struct drm_encoder *encoder; > >> struct dpu_encoder_virt *dpu_enc = NULL; > >> > >> dpu_enc = to_dpu_encoder_virt(drm_enc); > >> 5480 > >> *********************************************************** > >> 5485 return dpu_encoder_get_frame_count(encoder); > >> ************************************************************ I'm not quite following what's happening here, this doesn't look much like the function i see on cros. > >> > >> this just returns phys->vsync_cnt (which is just an atomic counter > >> which > >> doesnt reset during disable) > >> So in other words instead of relying on the hw register value which > >> can > >> be unpredictable when the timing engine is off, > >> use a sw counter > > > > I don't think that a sw counter will do the job, unless we never > > disable the vblank irq (or I am misunderstanding you).. the frame > > counter is expected to keep incrementing regardless of whether vblank > > is enabled or not. > > > > But it does sound like on suspend we need to store the current frame > > count, and add that offset later when asked for the current frame > > counter. > > > > BR, > > -R > the sw counter which i am referring to is already present in > dpu_encoder.c > its never reset during disable and should do the job. > > Yes, in principle yes, we need to store the current frame count before > suspend. > Thats what the phys->vsync_cnt will do and wont get reset. So i ran the code for both values, when it's on, i see them both having positive integers but they're not equal in any way. vsync count seems to be off ``` [ 83.627347] [drm:drm_mode_object_put] OBJ ID: 58 (1) [ 83.643559] get_frame_count->4887 3962<-vsync_cnt [ 83.643595] msm ae00000.mdss: [drm:drm_crtc_vblank_helper_get_vblank_timestamp_internal] crtc 0 : v p(0,-33)@ 83.606630 -> 83.607121 [e 2 us, 0 rep] [ 83.643663] get_frame_count->4887 3962<-vsync_cnt [ 83.643677] msm ae00000.mdss: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=38654714967, diff=1, hw=4887 hw_last=4886 [ 83.643722] msm ae00000.mdss: [drm:vblank_disable_fn] disabling vblank on crtc 0 [ 83.643750] get_frame_count->4887 3962<-vsync_cnt [ 83.643763] msm ae00000.mdss: [drm:drm_crtc_vblank_helper_get_vblank_timestamp_internal] crtc 0 : v p(0,-22)@ 83.606803 -> 83.607131 [e 1 us, 0 rep] [ 83.643811] get_frame_count->4887 3962<-vsync_cnt [ 83.643823] msm ae00000.mdss: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=38654714968, diff=0, hw=4887 hw_last=4887 ``` I see vsync always having values though (at enabling and disabling) ``` [ 82.887961] [drm:dpu_crtc_disable] crtc51 [ 82.887977] msm ae00000.mdss: [drm:drm_crtc_vblank_off] crtc 0, vblank enabled 1, inmodeset 0 [ 82.887998] get_frame_count->0 3939<-vsync_cnt [ 82.888008] msm ae00000.mdss: [drm:drm_crtc_vblank_helper_get_vblank_timestamp_internal] crtc 0 : v p(0,-38)@ 82.851427 -> 82.851992 [e 1 us, 0 rep] [ 82.888038] get_frame_count->0 3939<-vsync_cnt ``` should we create a s->frame_count_cached and save the value of frame_count whenever it's read when s->is_en? > > > > >> 5486 } > >> 5487 > >> 5488 return 0; > >> 5489 } > >> > >> > >> >> --- > >> >> drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c | 9 ++------- > >> >> drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h | 2 +- > >> >> 2 files changed, 3 insertions(+), 8 deletions(-) > >> >> > >> >> diff --git a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c > >> >> b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c > >> >> index 116e2b5b1a90f..c436d901629f3 100644 > >> >> --- a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c > >> >> +++ b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c > >> >> @@ -266,13 +266,8 @@ static void dpu_hw_intf_get_status( > >> >> > >> >> s->is_en = DPU_REG_READ(c, INTF_TIMING_ENGINE_EN); > >> >> s->is_prog_fetch_en = !!(DPU_REG_READ(c, INTF_CONFIG) & > >> >> BIT(31)); > >> >> - if (s->is_en) { > >> >> - s->frame_count = DPU_REG_READ(c, INTF_FRAME_COUNT); > >> >> - s->line_count = DPU_REG_READ(c, INTF_LINE_COUNT); > >> >> - } else { > >> >> - s->line_count = 0; > >> >> - s->frame_count = 0; > >> >> - } > >> >> + s->frame_count = DPU_REG_READ(c, INTF_FRAME_COUNT); > >> >> + s->line_count = DPU_REG_READ(c, INTF_LINE_COUNT); > >> >> } > >> >> > >> >> static u32 dpu_hw_intf_get_line_count(struct dpu_hw_intf *intf) > >> >> diff --git a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h > >> >> b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h > >> >> index 3568be80dab51..877ff48bfef04 100644 > >> >> --- a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h > >> >> +++ b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h > >> >> @@ -41,7 +41,7 @@ struct intf_prog_fetch { > >> >> struct intf_status { > >> >> u8 is_en; /* interface timing engine is enabled > >> >> or not */ > >> >> u8 is_prog_fetch_en; /* interface prog fetch counter is > >> >> enabled or not */ > >> >> - u32 frame_count; /* frame count since timing engine > >> >> enabled */ > >> >> + u32 frame_count; /* frame count since timing engine first > >> >> enabled */ > >> >> u32 line_count; /* current line count including > >> >> blanking */ > >> >> }; > >> >> > >> >> -- > >> >> 2.33.0.rc1.237.g0d66db33f3-goog > >> >>
diff = (cur_vblank - vblank->last) & max_vblank_count; cur_vblank comes from: cur_vblank = __get_vblank_counter(dev, pipe); When the value is 0, diff results in a negative number (a very large number as it's unsigned), which inflates the vblank count when the diff is added to the current vblank->count. [How] Read frame_count register whether interface timing engine is enabled or not. Fixes: IGT:kms_flip::modeset-vs-vblank-race-interruptible Tested on ChromeOS Trogdor(msm) Signed-off-by: Mark Yacoub <markyacoub@chromium.org> --- drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c | 9 ++------- drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h | 2 +- 2 files changed, 3 insertions(+), 8 deletions(-) diff --git a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c index 116e2b5b1a90f..c436d901629f3 100644 --- a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c +++ b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.c @@ -266,13 +266,8 @@ static void dpu_hw_intf_get_status( s->is_en = DPU_REG_READ(c, INTF_TIMING_ENGINE_EN); s->is_prog_fetch_en = !!(DPU_REG_READ(c, INTF_CONFIG) & BIT(31)); - if (s->is_en) { - s->frame_count = DPU_REG_READ(c, INTF_FRAME_COUNT); - s->line_count = DPU_REG_READ(c, INTF_LINE_COUNT); - } else { - s->line_count = 0; - s->frame_count = 0; - } + s->frame_count = DPU_REG_READ(c, INTF_FRAME_COUNT); + s->line_count = DPU_REG_READ(c, INTF_LINE_COUNT); } static u32 dpu_hw_intf_get_line_count(struct dpu_hw_intf *intf) diff --git a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h index 3568be80dab51..877ff48bfef04 100644 --- a/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h +++ b/drivers/gpu/drm/msm/disp/dpu1/dpu_hw_intf.h @@ -41,7 +41,7 @@ struct intf_prog_fetch { struct intf_status { u8 is_en; /* interface timing engine is enabled or not */ u8 is_prog_fetch_en; /* interface prog fetch counter is enabled or not */ - u32 frame_count; /* frame count since timing engine enabled */ + u32 frame_count; /* frame count since timing engine first enabled */ u32 line_count; /* current line count including blanking */ };
From: Mark Yacoub <markyacoub@google.com> [why] Reading frame count register used to get the vblank counter, which calls dpu_encoder_phys to get the frame count. Even when it's disabled, the vblank counter (through frame count) should return a valid value for the count. An invalid value of 0, when compared to vblank->last (in drm_vblank.c::drm_update_vblank_count()) returns an invalid number that throws off the vblank counter for the lifetime of the process. Rationale: In drm_vblank.c::drm_update_vblank_count(), the new diff is calculated through: