~emersion/public-inbox

3 2

Low FPS from wl_surface_frame callback

Details
Message ID
<CAMAFT9Xj17kW0eGiNVJO5dCEcTi-AODYoZMgS=qJqn07j0te8g@mail.gmail.com>
Sender timestamp
1552246801
DKIM signature
fail
Download raw message
Patch: +5 -0 DKIM signature: fail
Hi,

In a Wayland+EGL project I would like to to throttle animation to the
display refresh.
To do that, I'm using frame callbacks as your example

https://github.com/emersion/hello-wayland/tree/opengl-render-loop

except that I'm rendering from a different thread than the one driving
the Wayland
event loop.

However, I can't seem to attain 60 fps in my experiments, so I patched
your example
with

diff --git a/main.c b/main.c
index 06cf32f..cf381dc 100644
--- a/main.c
+++ b/main.c
@@ -94,6 +94,10 @@ static void render(void);

 static void frame_handle_done(void *data, struct wl_callback *callback,
                uint32_t time) {
+       static uint32_t lastTime;
+       uint32_t dt = time-lastTime;
+       lastTime = time;
+       printf("frame_handle_done: dt: %d\n", dt);
        wl_callback_destroy(callback);
        render();
 }
@@ -109,6 +113,7 @@ static void render(void) {

        long ms = (ts.tv_sec - last_frame.tv_sec) * 1000 +
                (ts.tv_nsec - last_frame.tv_nsec) / 1000000;
+       printf("render dt: %ld\n", ms);
        size_t inc = (dec + 1) % 3;
        color[inc] += ms / 2000.0f;
        color[dec] -= ms / 2000.0f;

and to my big surprise, your render loop doesn't attain 60 fps either. This is
a small sample of the timings:

frame_handle_done: dt: 23
render dt: 33
frame_handle_done: dt: 44
render dt: 33
frame_handle_done: dt: 25
render dt: 33
frame_handle_done: dt: 43
render dt: 33
frame_handle_done: dt: 21
render dt: 33
frame_handle_done: dt: 44
render dt: 33
frame_handle_done: dt: 24
render dt: 33
frame_handle_done: dt: 44
render dt: 33
frame_handle_done: dt: 23
render dt: 33
frame_handle_done: dt: 26
render dt: 16
frame_handle_done: dt: 40
render dt: 50
frame_handle_done: dt: 44
render dt: 33
frame_handle_done: dt: 53
render dt: 66

where only 1 out several frames attain ~16ms/frame.

As a sanity check, I ran glxgears on my system (Fedora 29, Intel HD530)
and it can easily reach 60 fps:

$ glxgears
292 frames in 5.0 seconds = 58.245 FPS
289 frames in 5.0 seconds = 57.702 FPS
289 frames in 5.0 seconds = 57.771 FPS

Do you know what I'm doing wrong?

 - elias
Details
Message ID
<teXUmnUwOgrrRdsMidr3k59SkNoYpUk5tpOQd72-BkI57ZBBC5Y0CfI-U3JS6TJfPT8df6NTbDF6xi19APqLdNk5nSTUq5YXaXV6WhRxHQ0=@emersion.fr>
In-Reply-To
<CAMAFT9Xj17kW0eGiNVJO5dCEcTi-AODYoZMgS=qJqn07j0te8g@mail.gmail.com> (view parent)
Sender timestamp
1552762586
DKIM signature
pass
Download raw message
Hi,

Sorry about the late reply. Here it is anyway :)

On Sunday, March 10, 2019 8:40 PM, Elias Naur <mail@eliasnaur.com> wrote:
> Hi,
>
> In a Wayland+EGL project I would like to to throttle animation to the
> display refresh.
> To do that, I'm using frame callbacks as your example
>
> https://github.com/emersion/hello-wayland/tree/opengl-render-loop
>
> except that I'm rendering from a different thread than the one driving
> the Wayland
> event loop.
>
> However, I can't seem to attain 60 fps in my experiments, so I patched
> your example
> with
>
> diff --git a/main.c b/main.c
> index 06cf32f..cf381dc 100644
> --- a/main.c
> +++ b/main.c
> @@ -94,6 +94,10 @@ static void render(void);
>
> static void frame_handle_done(void *data, struct wl_callback *callback,
> uint32_t time) {
>
> -         static uint32_t lastTime;
>
>
> -         uint32_t dt = time-lastTime;
>
>
> -         lastTime = time;
>
>
> -         printf("frame_handle_done: dt: %d\\n", dt);
>           wl_callback_destroy(callback);
>           render();
>
>
>
> }
> @@ -109,6 +113,7 @@ static void render(void) {
>
> long ms = (ts.tv_sec - last_frame.tv_sec) * 1000 +
> (ts.tv_nsec - last_frame.tv_nsec) / 1000000;
>
> -         printf("render dt: %ld\\n", ms);
>           size_t inc = (dec + 1) % 3;
>           color[inc] += ms / 2000.0f;
>           color[dec] -= ms / 2000.0f;
>
>
>
> and to my big surprise, your render loop doesn't attain 60 fps either. This is
> a small sample of the timings:
>
> frame_handle_done: dt: 23
> render dt: 33
> frame_handle_done: dt: 44
> render dt: 33
> frame_handle_done: dt: 25
> render dt: 33
> frame_handle_done: dt: 43
> render dt: 33
> frame_handle_done: dt: 21
> render dt: 33
> frame_handle_done: dt: 44
> render dt: 33
> frame_handle_done: dt: 24
> render dt: 33
> frame_handle_done: dt: 44
> render dt: 33
> frame_handle_done: dt: 23
> render dt: 33
> frame_handle_done: dt: 26
> render dt: 16
> frame_handle_done: dt: 40
> render dt: 50
> frame_handle_done: dt: 44
> render dt: 33
> frame_handle_done: dt: 53
> render dt: 66
>
> where only 1 out several frames attain ~16ms/frame.

When I run your example, I get:

frame_handle_done: dt: 16
render dt: 16
frame_handle_done: dt: 17
render dt: 16
frame_handle_done: dt: 17
render dt: 16
frame_handle_done: dt: 16
render dt: 16
frame_handle_done: dt: 17
render dt: 16
frame_handle_done: dt: 16
render dt: 17

which seems correct (there might be rounding issues with `ms`
computation in the `render` function).

What compositor are you using?

> As a sanity check, I ran glxgears on my system (Fedora 29, Intel HD530)
> and it can easily reach 60 fps:
>
> $ glxgears
> 292 frames in 5.0 seconds = 58.245 FPS
> 289 frames in 5.0 seconds = 57.702 FPS
> 289 frames in 5.0 seconds = 57.771 FPS
>
> Do you know what I'm doing wrong?
>
> -   elias
Details
Message ID
<CAMAFT9WBQSmWr8iXo82ebQDx7FF1ZWBZhAEHWM9jPtQPb+2gYg@mail.gmail.com>
In-Reply-To
<teXUmnUwOgrrRdsMidr3k59SkNoYpUk5tpOQd72-BkI57ZBBC5Y0CfI-U3JS6TJfPT8df6NTbDF6xi19APqLdNk5nSTUq5YXaXV6WhRxHQ0=@emersion.fr> (view parent)
Sender timestamp
1552798685
DKIM signature
fail
Download raw message
DKIM signature: fail
On Sat, Mar 16, 2019 at 7:56 PM Simon Ser <contact@emersion.fr> wrote:
>
> Hi,
>
> Sorry about the late reply. Here it is anyway :)
>
> On Sunday, March 10, 2019 8:40 PM, Elias Naur <mail@eliasnaur.com> wrote:
> > Hi,
> >
> > In a Wayland+EGL project I would like to to throttle animation to the
> > display refresh.
> > To do that, I'm using frame callbacks as your example
> >
> > https://github.com/emersion/hello-wayland/tree/opengl-render-loop
> >
> > except that I'm rendering from a different thread than the one driving
> > the Wayland
> > event loop.
> >
> > However, I can't seem to attain 60 fps in my experiments, so I patched
> > your example
> > with
> >
> > diff --git a/main.c b/main.c
> > index 06cf32f..cf381dc 100644
> > --- a/main.c
> > +++ b/main.c
> > @@ -94,6 +94,10 @@ static void render(void);
> >
> > static void frame_handle_done(void *data, struct wl_callback *callback,
> > uint32_t time) {
> >
> > -         static uint32_t lastTime;
> >
> >
> > -         uint32_t dt = time-lastTime;
> >
> >
> > -         lastTime = time;
> >
> >
> > -         printf("frame_handle_done: dt: %d\\n", dt);
> >           wl_callback_destroy(callback);
> >           render();
> >
> >
> >
> > }
> > @@ -109,6 +113,7 @@ static void render(void) {
> >
> > long ms = (ts.tv_sec - last_frame.tv_sec) * 1000 +
> > (ts.tv_nsec - last_frame.tv_nsec) / 1000000;
> >
> > -         printf("render dt: %ld\\n", ms);
> >           size_t inc = (dec + 1) % 3;
> >           color[inc] += ms / 2000.0f;
> >           color[dec] -= ms / 2000.0f;
> >
> >
> >
> > and to my big surprise, your render loop doesn't attain 60 fps either. This is
> > a small sample of the timings:
> >
> > frame_handle_done: dt: 23
> > render dt: 33
> > frame_handle_done: dt: 44
> > render dt: 33
> > frame_handle_done: dt: 25
> > render dt: 33
> > frame_handle_done: dt: 43
> > render dt: 33
> > frame_handle_done: dt: 21
> > render dt: 33
> > frame_handle_done: dt: 44
> > render dt: 33
> > frame_handle_done: dt: 24
> > render dt: 33
> > frame_handle_done: dt: 44
> > render dt: 33
> > frame_handle_done: dt: 23
> > render dt: 33
> > frame_handle_done: dt: 26
> > render dt: 16
> > frame_handle_done: dt: 40
> > render dt: 50
> > frame_handle_done: dt: 44
> > render dt: 33
> > frame_handle_done: dt: 53
> > render dt: 66
> >
> > where only 1 out several frames attain ~16ms/frame.
>
> When I run your example, I get:
>
> frame_handle_done: dt: 16
> render dt: 16
> frame_handle_done: dt: 17
> render dt: 16
> frame_handle_done: dt: 17
> render dt: 16
> frame_handle_done: dt: 16
> render dt: 16
> frame_handle_done: dt: 17
> render dt: 16
> frame_handle_done: dt: 16
> render dt: 17
>
> which seems correct (there might be rounding issues with `ms`
> computation in the `render` function).
>

Indeed. I also tried your example on a different machine (x1 carbon 2012)
and it had the expected ~60Hz timings.
I would have dismissed my other timings as a failure to composite my 4K
display at 60Hz, if it weren't for my machine specs and that the glxgears
test runs at 60Hz.
My other theory was that surface_frame_done is not for animating surface
content, but your answer leads me to believe that's not the case.

> What compositor are you using?
>

The one that came with Fedora. I believe that's Mutter.

> > As a sanity check, I ran glxgears on my system (Fedora 29, Intel HD530)
> > and it can easily reach 60 fps:
> >
> > $ glxgears
> > 292 frames in 5.0 seconds = 58.245 FPS
> > 289 frames in 5.0 seconds = 57.702 FPS
> > 289 frames in 5.0 seconds = 57.771 FPS
> >
> > Do you know what I'm doing wrong?
> >
> > -   elias
>
>
Details
Message ID
<qL9QP_Q5DrjdaNc5nd3zkQ3DHgHo85maZV4FkISDpra6sUoYU23xWw44KzUufCroYkVXCA75-D3zXO6v6UKMlRIUOI-a4hC0iETyx0-hKtE=@emersion.fr>
In-Reply-To
<CAMAFT9WBQSmWr8iXo82ebQDx7FF1ZWBZhAEHWM9jPtQPb+2gYg@mail.gmail.com> (view parent)
Sender timestamp
1552819236
DKIM signature
pass
Download raw message
On Sunday, March 17, 2019 6:58 AM, Elias Naur <mail@eliasnaur.com> wrote:
> Indeed. I also tried your example on a different machine (x1 carbon 2012)
> and it had the expected ~60Hz timings.
> I would have dismissed my other timings as a failure to composite my 4K
> display at 60Hz, if it weren't for my machine specs and that the glxgears
> test runs at 60Hz.
> My other theory was that surface_frame_done is not for animating surface
> content, but your answer leads me to believe that's not the case.

The very purpose of frame callbacks is to animate surface content, so
it should work. Once the surface is visible, you should get one frame
callback "done" event per vblank.

> > What compositor are you using?
>
> The one that came with Fedora. I believe that's Mutter.

Yeah. This might as well be a Mutter bug.