mouse move causes framerate speedup (1.1beta)

[Tartley]

Hey there,

Moving the mouse causes the framerate of my Pyglet application to
increase massively (from the requested 30fps to about 80fps.) When I
stop moving the mouse, the framerate becomes very slow and jerky
(alternating between frames of ~2ms and ~250ms). This jerkiness lasts
for about as long as the duration of the former mouse movement.
Presumably the event loop is trying to slow down to compensate for the
very fast frames earlier.

Even when I don't touch the mouse, while the framerate hovers around
30fps, every so often (a few times per second) I get a really fast
frame (~2ms), followed by one or two really slow ones (~90ms.)

Presumably events are short-cutting the sleep that happens between
each frame. Mouse events come in a prolific stream, causing every
frame to be shortened. Other events come occasionally, causing the
sporadic deviations from 30fps.

Also, possibly related, I am still seeing tearing when I add some
rapidly moving polygons into the draw event, even though printing
window.vsync reports True. Changing vsync to False does not change the
framerate issue.

I've reduced my code to what I *believe* is a fairly canonical event
loop (below)

This is on 1.1beta, Ubuntu 8.04, on a dual core thinkpad T60. I'll try
it out on v1.0, see how that goes, post results here. In the meantime,
Any ideas or suggestions much appreciated.


---------------------------
from pyglet import app, clock, window

win = window.Window(vsync=True)
clockDisplay = clock.ClockDisplay()
ticks = []

def update(dt):
ticks.append(dt)

@win.event
def on_draw():
win.clear()
clockDisplay.draw()


clock.set_fps_limit(30)
clock.schedule(update)
app.run()
print "Tick times in ms:", ", ".join("%.0f" % (dt*1000) for dt in
ticks)
---------------------------


Using the above code, I get the following output (with CR and comments
added manually to document what I think is going on:


----------------------------
Tick times in ms:
# always start with twenty or so very fast frames (1ms per frame.)
# Unexpected but I can live with it.
0 17 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1

# then it settles down to what I requested 30fps (==33ms/frame.)
# But it is very uneven
# The min during this 'stable' period is 2ms and the max is 82ms
19 32 37 31 29 2 70 31 36 32 33 31 17 2 82 36 32 31 37 32 36 31 32 37
32 31 36 17 48 31 36 33 32 36 31 5 64 31 36 33 31 36 21 43 36 32 33 31
37 31 9 60 31 36 32 33 31 29 43

# At this point I started moving the mouse. This causes a massive
frame
# rate increase, presumably because the mouse event is short-cutting
the
# sleep between frames.
8 12 12 10 14 11 12 11 12 12 12 12 12 12 13 12 10 11 12 12 11 11 13 11
13 12 11 12 11 12 11 12 2 10 12 12 12 11 12 13 6 5 12 11 12 12 12 12
12 12 11 12 12 11 11 13 10 12 11 12 11 13 12 12 13 13 12 12 13 12 12
10 10 11 12 11 11 13 11 12 12 12 11 12 6 7 2 9 11 11 11 13 12 12 11 12
13 11 12 11 12 12 12 12 12 11 11 6 5

# At this point I stopped moving the mouse. Now there is a period of
very
# jerky frames alternating between very short and very long,
presumably
# while the eventloop attempts to compensate for the short frames
earlier.
251 248 2 250 2 250 2 250 2 250 2 250 2 250 2 250 2 250 3 249 2 250 2
190

# eventually it settles back down to 30fps but it is extremely uneven
again.
# Min=2ms max=94ms
36 24 2 75 32 32 36 31 36 8 2 86 36 32 36 33 28 39 32 33 31 36 33 31
17 51 36 33 31 32 37 32 31 36 33 32 36 32 31 21 51 33 31 32 36 33 31 5
63 33 31 36 32 36 20 48 32 32 3 3 31 36 32 5 2 94 31 40 29

# final frame is always very long. No big deal.
150

[Tartley]

None of this is a problem under v1.0. Framerate is rock-solid, no
tearing is visible. Code to use v1.0 API looks like:

---------------------------
import sys
from os.path import abspath, dirname
sys.path.insert(0, abspath('.'))

from pyglet import window, clock, version, __file__
print "Pyglet %s [%s]" % (version, dirname(__file__))

win = window.Window(vsync=True)
clockDisplay = clock.ClockDisplay()
ticks = []

def update(dt):
ticks.append(dt)

def on_draw():
win.clear()
clockDisplay.draw()

clock.set_fps_limit(30)

while not win.has_exit:
dt = clock.tick()
update(dt)
win.dispatch_events()
on_draw()
win.flip()

print "Tick times in ms:", ", ".join("%.0f" % (dt*1000) for dt in
ticks)
---------------

Output looks like:

Pyglet 1.0 [/home/jhartley/projects/sole-scion/src/pyglet]
Tick times in ms: 0, 67, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33,
33, 33, 33, 33,
33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33,
33, 33, 33, 33,
33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33, 33,
33, 33, 33, 33

[Tartley]

I'm seeing the problem on 1.1beta2, to be precise.

[Tartley]

Oh, and, if I use the Pyglet v1.0 style code shown above (the version
with the explicit event loop, "while not win.has_exit:") but run it
against Pyglet 1.1beta2, then I see no problems either. The behaviour
is then perfect, just like using Pyglet1.0

[Alex Holkner]

set_fps_limit can't really do its job in the pyglet 1.1-style loop.
An equivalent and better performing solution is to delete the call to
set_fps_limit, and instead schedule your update function at the
desired rate:

clock.schedule_interval(update, 1/30.0)

I imagine this will solve your framerate issue under pyglet 1.1. I'll
have a look and see if there's an easy fix for set_fps_limit,
otherwise I'll probably mark it deprecated in the future.

Alex.

[Tartley]

Hey Alex,

Thanks heaps for the response.

I've tried that out, and am now using the exact canonical 'hello
world' example, cut and paste from the programming guide, and it does
help, but I'm still very confused.

My 'update' function now gets called every 33 to 37ms, no matter what
happens. This is not quite the 30fps I asked for, but is much
improved, and is unaffected by mouse events.

However, on_draw() gets called at 45 to 55 fps, and this rises to
120fps when I move the mouse. So many of my calls to on_draw() are
redundant (drawing the same thing as last frame)

It no longer adds the extra-slow frames after I stop moving the mouse
- now it drops directly back to ~50fps.

I am still seeing tearing.

I'm looking for on_draw() and update() to be called in lockstep, one
directly after the other, with the built-in display buffer flips being
vsynched to monitor refreshes. Am I being dumb?

Thanks for any suggestions anyone has. I'll keep playing with it and
report any findings, but am beginning to be tempted to write my own
explicit event loop. The programming guide recommends against it
though.

My code now looks like:

----------------------------------
import pyglet

window = pyglet.window.Window()
clockDisplay = pyglet.clock.ClockDisplay()
label = pyglet.text.Label('Hello, world',
font_name='Times New Roman',
font_size=36,
x=window.width//2, y=window.height//2,
anchor_x='center', anchor_y='center')

ticks = []

def update(dt):
ticks.append(dt)

@window.event
def on_draw():
window.clear()
label.draw()
clockDisplay.draw()

pyglet.clock.schedule_interval(update, 1.0/30)
pyglet.app.run()
print "ticks:", " ".join("%.1f" % (t*1000) for t in ticks)





On Jun 20, 6:39 pm, "Alex Holkner" <alex.holk...@gmail.com> wrote:

[Alex Holkner]

On Tue, Jun 24, 2008 at 7:11 AM, Tartley <tar...@tartley.com> wrote:
>
> Hey Alex,
>
> Thanks heaps for the response.
>
> I've tried that out, and am now using the exact canonical 'hello
> world' example, cut and paste from the programming guide, and it does
> help, but I'm still very confused.
>
> My 'update' function now gets called every 33 to 37ms, no matter what
> happens. This is not quite the 30fps I asked for, but is much
> improved, and is unaffected by mouse events.
>
> However, on_draw() gets called at 45 to 55 fps, and this rises to
> 120fps when I move the mouse. So many of my calls to on_draw() are
> redundant (drawing the same thing as last frame)

pyglet assumes that the window needs to be repainted after any event,
including mouse events. You can override this by setting
window.invalid=False during your on_draw() handler. This prevents
on_draw being called again until invalid is set to True (for example,
during your update() function). This is a
new/experimental/undocumented feature.

> I am still seeing tearing.

Try:

python tests/test.py WINDOW_SET_VSYNC

which should make it abundantly clear whether or not your video card
supports vsync.

Alex.

[Tartley]

Thanks once again for the assists, Alex.

As you anticipated, the WINDOW_SET_VSYNC test shows that vsync is not
being honoured. (that's a cool test - much clearer than squinting at
moving polygons like I was trying to do.) I'll look around in my
driver / X config, see if there's anything I can do about that.

I'll play with the window invalidation mechanism you outline, see what
happens.

Many thanks,

Jonathan



On Jun 23, 6:06 pm, "Alex Holkner" <alex.holk...@gmail.com> wrote:

[Tartley]

I installed the ATI Catalyst Control Center, enabled vsync from there.
It seems to store its configuration in /etc/ati/amdpcsdb. The
WINDOW_SET_VSYNC shows no tearing.

I don't think the following is Pyglet's fault, since I see it on
glxgears too, but for the record...

Fullscreen windows still show a single tear about 1/4 down from the
top of the screen. It is present on every frame and is extremely
noticeable, both for alternating background colors and for moving
polygons.

I'll keep checking out my driver and X config.