* [PATCH V2] drm/vkms: Avoid extra discount in the timestamp value
@ 2019-06-05 2:45 Rodrigo Siqueira
2019-06-05 12:22 ` Daniel Vetter
0 siblings, 1 reply; 3+ messages in thread
From: Rodrigo Siqueira @ 2019-06-05 2:45 UTC (permalink / raw)
To: Simon Ser, Ville Syrjala, Shayenne Moura, Haneen Mohammed,
Daniel Vetter, David Airlie
Cc: dri-devel, linux-kernel, 18oliveira.charles
[-- Attachment #1: Type: text/plain, Size: 3305 bytes --]
After the commit def35e7c5926 ("drm/vkms: Bugfix extra vblank frame")
some of the crc tests started to fail in the vkms with the following
error:
[drm:drm_crtc_add_crc_entry [drm]] *ERROR* Overflow of CRC buffer,
userspace reads too slow.
[drm] failed to queue vkms_crc_work_handle
...
The aforementioned commit fixed the extra vblank added by
`drm_crtc_arm_vblank_event()` which is invoked inside
`vkms_crtc_atomic_flush()` if the vblank event count was zero, otherwise
`drm_crtc_send_vblank_event()` is invoked. The fix was implemented in
`vkms_get_vblank_timestamp()` by subtracting one period from the current
timestamp, as the code snippet below illustrates:
if (!in_vblank_irq)
*vblank_time -= output->period_ns;
The above fix works well when `drm_crtc_arm_vblank_event()` is invoked.
However, it does not properly work when `drm_crtc_send_vblank_event()`
executes since it subtracts the correct timestamp, which it shouldn't.
In this case, the `drm_crtc_accurate_vblank_count()` function will
returns the wrong frame number, which generates the aforementioned
error. Such decrease in `get_vblank_timestamp()` produce a negative
number in the following calculation within `drm_update_vblank_count()`:
u64 diff_ns = ktime_to_ns(ktime_sub(t_vblank, vblank->time));
After this operation, the DIV_ROUND_CLOSEST_ULL macro is invoked using
diff_ns with a negative number, which generates an undefined result;
therefore, the returned frame is a huge and incorrect number. Finally,
the code below is part of the `vkms_crc_work_handle()`, note that the
while loop depends on the returned value from
`drm_crtc_accurate_vblank_count()` which may cause the loop to take a
long time to finish in case of huge value.
frame_end = drm_crtc_accurate_vblank_count(crtc);
while (frame_start <= frame_end)
drm_crtc_add_crc_entry(crtc, true, frame_start++, &crc32);
This commit fixes this issue by checking if the vblank timestamp
corresponding to the current software vblank counter is equal to the
current vblank; if they are equal, it means that
`drm_crtc_send_vblank_event()` was invoked and vkms does not need to
discount the extra vblank, otherwise, `drm_crtc_arm_vblank_event()` was
executed and vkms have to discount the extra vblank. This fix made the
CRC tests work again whereas keep all tests from kms_flip working as
well.
V2: Update commit message
Signed-off-by: Rodrigo Siqueira <rodrigosiqueiramelo@gmail.com>
Signed-off-by: Shayenne Moura <shayenneluzmoura@gmail.com>
---
drivers/gpu/drm/vkms/vkms_crtc.c | 4 ++++
1 file changed, 4 insertions(+)
diff --git a/drivers/gpu/drm/vkms/vkms_crtc.c b/drivers/gpu/drm/vkms/vkms_crtc.c
index 7508815fac11..3ce60e66673e 100644
--- a/drivers/gpu/drm/vkms/vkms_crtc.c
+++ b/drivers/gpu/drm/vkms/vkms_crtc.c
@@ -74,9 +74,13 @@ bool vkms_get_vblank_timestamp(struct drm_device *dev, unsigned int pipe,
{
struct vkms_device *vkmsdev = drm_device_to_vkms_device(dev);
struct vkms_output *output = &vkmsdev->output;
+ struct drm_vblank_crtc *vblank = &dev->vblank[pipe];
*vblank_time = output->vblank_hrtimer.node.expires;
+ if (*vblank_time == vblank->time)
+ return true;
+
if (!in_vblank_irq)
*vblank_time -= output->period_ns;
--
2.21.0
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply related [flat|nested] 3+ messages in thread
* Re: [PATCH V2] drm/vkms: Avoid extra discount in the timestamp value
2019-06-05 2:45 [PATCH V2] drm/vkms: Avoid extra discount in the timestamp value Rodrigo Siqueira
@ 2019-06-05 12:22 ` Daniel Vetter
0 siblings, 0 replies; 3+ messages in thread
From: Daniel Vetter @ 2019-06-05 12:22 UTC (permalink / raw)
To: Rodrigo Siqueira
Cc: Simon Ser, Ville Syrjala, Shayenne Moura, Haneen Mohammed,
Daniel Vetter, David Airlie, dri-devel, linux-kernel,
18oliveira.charles
On Tue, Jun 04, 2019 at 11:45:43PM -0300, Rodrigo Siqueira wrote:
> After the commit def35e7c5926 ("drm/vkms: Bugfix extra vblank frame")
> some of the crc tests started to fail in the vkms with the following
> error:
>
> [drm:drm_crtc_add_crc_entry [drm]] *ERROR* Overflow of CRC buffer,
> userspace reads too slow.
> [drm] failed to queue vkms_crc_work_handle
> ...
>
> The aforementioned commit fixed the extra vblank added by
> `drm_crtc_arm_vblank_event()` which is invoked inside
> `vkms_crtc_atomic_flush()` if the vblank event count was zero, otherwise
> `drm_crtc_send_vblank_event()` is invoked. The fix was implemented in
> `vkms_get_vblank_timestamp()` by subtracting one period from the current
> timestamp, as the code snippet below illustrates:
>
> if (!in_vblank_irq)
> *vblank_time -= output->period_ns;
>
> The above fix works well when `drm_crtc_arm_vblank_event()` is invoked.
> However, it does not properly work when `drm_crtc_send_vblank_event()`
> executes since it subtracts the correct timestamp, which it shouldn't.
> In this case, the `drm_crtc_accurate_vblank_count()` function will
> returns the wrong frame number, which generates the aforementioned
> error. Such decrease in `get_vblank_timestamp()` produce a negative
> number in the following calculation within `drm_update_vblank_count()`:
>
> u64 diff_ns = ktime_to_ns(ktime_sub(t_vblank, vblank->time));
>
> After this operation, the DIV_ROUND_CLOSEST_ULL macro is invoked using
> diff_ns with a negative number, which generates an undefined result;
> therefore, the returned frame is a huge and incorrect number. Finally,
> the code below is part of the `vkms_crc_work_handle()`, note that the
> while loop depends on the returned value from
> `drm_crtc_accurate_vblank_count()` which may cause the loop to take a
> long time to finish in case of huge value.
>
> frame_end = drm_crtc_accurate_vblank_count(crtc);
> while (frame_start <= frame_end)
> drm_crtc_add_crc_entry(crtc, true, frame_start++, &crc32);
>
> This commit fixes this issue by checking if the vblank timestamp
> corresponding to the current software vblank counter is equal to the
> current vblank; if they are equal, it means that
> `drm_crtc_send_vblank_event()` was invoked and vkms does not need to
> discount the extra vblank, otherwise, `drm_crtc_arm_vblank_event()` was
> executed and vkms have to discount the extra vblank. This fix made the
> CRC tests work again whereas keep all tests from kms_flip working as
> well.
>
> V2: Update commit message
>
> Signed-off-by: Rodrigo Siqueira <rodrigosiqueiramelo@gmail.com>
> Signed-off-by: Shayenne Moura <shayenneluzmoura@gmail.com>
Thanks a lot for typing up this commit message. I'm still not following
what's going on (this stuff is tricky), but now I think I can at least ask
useful scenarios.
For my understanding: Things go wrong when in the function
vkms_crtc_atomic_flush() the call to drm_crtc_vblank_get() returns 0, and
we call drm_crtc_send_vblank_event() directly? I'm not 100% from your
description above whether that's the failure case where everything blows
up.
The other part I'm having a hard time understanding: If we are in the case
where we call drm_crtc_send_vblank_event() directly, how do we end up in
the vkms_get_vblank_timestamp().
From what I can see there's not caller to where we sample a new vblank ...
I think a full backtrace that hits the new condition you're adding to
understand when exactly we're hitting it would be perfect.
> ---
> drivers/gpu/drm/vkms/vkms_crtc.c | 4 ++++
> 1 file changed, 4 insertions(+)
>
> diff --git a/drivers/gpu/drm/vkms/vkms_crtc.c b/drivers/gpu/drm/vkms/vkms_crtc.c
> index 7508815fac11..3ce60e66673e 100644
> --- a/drivers/gpu/drm/vkms/vkms_crtc.c
> +++ b/drivers/gpu/drm/vkms/vkms_crtc.c
> @@ -74,9 +74,13 @@ bool vkms_get_vblank_timestamp(struct drm_device *dev, unsigned int pipe,
> {
> struct vkms_device *vkmsdev = drm_device_to_vkms_device(dev);
> struct vkms_output *output = &vkmsdev->output;
> + struct drm_vblank_crtc *vblank = &dev->vblank[pipe];
>
> *vblank_time = output->vblank_hrtimer.node.expires;
>
> + if (*vblank_time == vblank->time)
> + return true;
Ok, I think with the above I do now have a rough idea what's going wrong.
I think that would be a bug in the drm_vblank.c. Or at least it could be,
I think I first need to better understand still what's going on here to
decided that.
I have a bit a hunch this is fallout from our vblank fudging, but I guess
we'll see.
It's definitely clear that things blow up if the vblank time somehow goes
backwards, but I don't understand yet how that's possible.
-Daniel
> +
> if (!in_vblank_irq)
> *vblank_time -= output->period_ns;
>
> --
> 2.21.0
>
--
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: [PATCH V2] drm/vkms: Avoid extra discount in the timestamp value
@ 2019-06-05 12:22 ` Daniel Vetter
0 siblings, 0 replies; 3+ messages in thread
From: Daniel Vetter @ 2019-06-05 12:22 UTC (permalink / raw)
To: Rodrigo Siqueira
Cc: Haneen Mohammed, David Airlie, linux-kernel, dri-devel,
Simon Ser, Shayenne Moura, 18oliveira.charles
On Tue, Jun 04, 2019 at 11:45:43PM -0300, Rodrigo Siqueira wrote:
> After the commit def35e7c5926 ("drm/vkms: Bugfix extra vblank frame")
> some of the crc tests started to fail in the vkms with the following
> error:
>
> [drm:drm_crtc_add_crc_entry [drm]] *ERROR* Overflow of CRC buffer,
> userspace reads too slow.
> [drm] failed to queue vkms_crc_work_handle
> ...
>
> The aforementioned commit fixed the extra vblank added by
> `drm_crtc_arm_vblank_event()` which is invoked inside
> `vkms_crtc_atomic_flush()` if the vblank event count was zero, otherwise
> `drm_crtc_send_vblank_event()` is invoked. The fix was implemented in
> `vkms_get_vblank_timestamp()` by subtracting one period from the current
> timestamp, as the code snippet below illustrates:
>
> if (!in_vblank_irq)
> *vblank_time -= output->period_ns;
>
> The above fix works well when `drm_crtc_arm_vblank_event()` is invoked.
> However, it does not properly work when `drm_crtc_send_vblank_event()`
> executes since it subtracts the correct timestamp, which it shouldn't.
> In this case, the `drm_crtc_accurate_vblank_count()` function will
> returns the wrong frame number, which generates the aforementioned
> error. Such decrease in `get_vblank_timestamp()` produce a negative
> number in the following calculation within `drm_update_vblank_count()`:
>
> u64 diff_ns = ktime_to_ns(ktime_sub(t_vblank, vblank->time));
>
> After this operation, the DIV_ROUND_CLOSEST_ULL macro is invoked using
> diff_ns with a negative number, which generates an undefined result;
> therefore, the returned frame is a huge and incorrect number. Finally,
> the code below is part of the `vkms_crc_work_handle()`, note that the
> while loop depends on the returned value from
> `drm_crtc_accurate_vblank_count()` which may cause the loop to take a
> long time to finish in case of huge value.
>
> frame_end = drm_crtc_accurate_vblank_count(crtc);
> while (frame_start <= frame_end)
> drm_crtc_add_crc_entry(crtc, true, frame_start++, &crc32);
>
> This commit fixes this issue by checking if the vblank timestamp
> corresponding to the current software vblank counter is equal to the
> current vblank; if they are equal, it means that
> `drm_crtc_send_vblank_event()` was invoked and vkms does not need to
> discount the extra vblank, otherwise, `drm_crtc_arm_vblank_event()` was
> executed and vkms have to discount the extra vblank. This fix made the
> CRC tests work again whereas keep all tests from kms_flip working as
> well.
>
> V2: Update commit message
>
> Signed-off-by: Rodrigo Siqueira <rodrigosiqueiramelo@gmail.com>
> Signed-off-by: Shayenne Moura <shayenneluzmoura@gmail.com>
Thanks a lot for typing up this commit message. I'm still not following
what's going on (this stuff is tricky), but now I think I can at least ask
useful scenarios.
For my understanding: Things go wrong when in the function
vkms_crtc_atomic_flush() the call to drm_crtc_vblank_get() returns 0, and
we call drm_crtc_send_vblank_event() directly? I'm not 100% from your
description above whether that's the failure case where everything blows
up.
The other part I'm having a hard time understanding: If we are in the case
where we call drm_crtc_send_vblank_event() directly, how do we end up in
the vkms_get_vblank_timestamp().
From what I can see there's not caller to where we sample a new vblank ...
I think a full backtrace that hits the new condition you're adding to
understand when exactly we're hitting it would be perfect.
> ---
> drivers/gpu/drm/vkms/vkms_crtc.c | 4 ++++
> 1 file changed, 4 insertions(+)
>
> diff --git a/drivers/gpu/drm/vkms/vkms_crtc.c b/drivers/gpu/drm/vkms/vkms_crtc.c
> index 7508815fac11..3ce60e66673e 100644
> --- a/drivers/gpu/drm/vkms/vkms_crtc.c
> +++ b/drivers/gpu/drm/vkms/vkms_crtc.c
> @@ -74,9 +74,13 @@ bool vkms_get_vblank_timestamp(struct drm_device *dev, unsigned int pipe,
> {
> struct vkms_device *vkmsdev = drm_device_to_vkms_device(dev);
> struct vkms_output *output = &vkmsdev->output;
> + struct drm_vblank_crtc *vblank = &dev->vblank[pipe];
>
> *vblank_time = output->vblank_hrtimer.node.expires;
>
> + if (*vblank_time == vblank->time)
> + return true;
Ok, I think with the above I do now have a rough idea what's going wrong.
I think that would be a bug in the drm_vblank.c. Or at least it could be,
I think I first need to better understand still what's going on here to
decided that.
I have a bit a hunch this is fallout from our vblank fudging, but I guess
we'll see.
It's definitely clear that things blow up if the vblank time somehow goes
backwards, but I don't understand yet how that's possible.
-Daniel
> +
> if (!in_vblank_irq)
> *vblank_time -= output->period_ns;
>
> --
> 2.21.0
>
--
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
^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2019-06-05 12:23 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-06-05 2:45 [PATCH V2] drm/vkms: Avoid extra discount in the timestamp value Rodrigo Siqueira
2019-06-05 12:22 ` Daniel Vetter
2019-06-05 12:22 ` Daniel Vetter
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.