Framerate weirdness, motion weirdness

Scripting Issues
1

I’m having two problems related to time. I suspect they might be related, but I’m far from sure of that.

First problem: I’m using Panda’s built-in framerate meter. On occasion, the framerate will be displayed as going above 60 FPS (up to around 80). Since my refresh rate is set to 60 and vsync is on (and it really is on… there’s no tearing), this isn’t logically possible. It seems to happen as a slingshot effect: I’ll do something graphically expensive which drops the framerate to pretty low for half a second then goes away, and as a result the framerate will go to 30-something, then 80, then back to 60.

Second problem: Framerate-independent motion seems to be awfully non-constant. Objects move with varying velocity even when they shouldn’t. As a minimal test, I’m doing this:

testobj = loader.loadModel('testmodel.egg')
testobj.reparentTo(render2d)

def test_update(task):
    dT = globalClock.getDt()
    testobj.setR(testobj.getR()+(dT*60))
    return PandaTask.cont

taskMgr.add(test_update, 'test_update')

So, basically, the model should do one complete rotation every six seconds. Instead, its velocity jerks up and down every second or so, sometimes rotating twice as fast as other times.

Any idea on either of these? Other than getDt(), I’m not touching globalClock in any way.

2

Hmm. By chance, do you have a multi-core CPU? There is a known bug with certain multi-core motherboards, on certain versions of Windows, where the clock can go screwy. This happens whenever the OS decides to migrate the Panda process from one core to the other, which can happen at random.

If so, the workaround is to constrain the process to stick to one CPU, for instance with:

client-cpu-affinity-mask 1

in your Config.prc file.

Another possibility is that your time-of-day clock is screwy, and Panda is trying to sync to that, causing erratic time measurements. I don’t think it does this by default, though, but just in case you can also put:

paranoid-clock 0

in your Config.prc file.

David

3

My CPU is single core, and my time-of-day clock seems fine. Tried each of those settings, though, with no luck.

A bit more testing makes things look even weirder. I stuck an extra alpha-blended object into my scene (an indicator light with an interval that fades itself out after 0.5 seconds and then removes itself). Result: The framerate went higher. Creating one object every 60 frames, the framerate was pretty consistently in the 100-130 FPS range.

EDIT: Actually, that may not be true. Tried taking the blended object out again, and the framerate stayed up. Hmmm…

4

Alright, new datapoint. Added this to the beginning of my program:

globalClock.setMode(ClockObject.MNonRealTime)
globalClock.setDt(1.0/60.0)

Result: Well, the framerate meter showed exactly 60 FPS, of course (even when it missed a vsync). More interestingly, though, the velocity smoothed out entirely. So it looks like I can count on the display clock, at least. Still, that doesn’t really seem like a tenable solution.

5

Hmm, have you tried looking at your frames in pstats? I’m curious what it looks like there when your frame rate jumps higher than your vsync.

Also, what happens if you turn off vsync? I’ve seen some drivers that do a really poor job of vsync, holding some frames too long and queuing up additional frames behind them, so that when the frames pop off the queue they appear to be rendering impossibly quickly.

You could also try switching between OpenGL and DirectX; if it really is something weird in your driver’s vsync support, this might change it.

David

6

Haven’t checked (or, indeed, ever used) pstats… I’ll do that in a bit (after trying a driver update… see later).

Enabling debug spew for express (why “express”?) shows the following:

:express:clock(debug): Will report time scale, now 77.8243%, tod_age = 1.51563, time_age = 1.17953, ratio = 1.28494
:express:clock(debug): Will report time scale, now 70.6445%, tod_age = 1.9375, time_age = 1.36874, ratio = 1.10163
:express:clock(debug): Clock is behind by 0.50062s; speeding up to correct.
:express:clock(debug): Will report time scale, now 64.1527%, tod_age = 2.60938, time_age = 1.67399, ratio = 1.10119
:express:clock(debug): Will report time scale, now 58.2215%, tod_age = 3, time_age = 1.74665, ratio = 1.10187
:express:clock(debug): Will report time scale, now 52.7676%, tod_age = 3, time_age = 1.58303, ratio = 1.10336
:express:clock(debug): Will report time scale, now 47.9276%, tod_age = 3, time_age = 1.43783, ratio = 1.10099
:express:clock: Clock appears to be running at 40% real time.
:express:clock(debug): Will report time scale, now 50.7287%, tod_age = 3.01563, time_age = 1.52979, ratio = 0.89616
:express:clock(debug): Clock back up to real time.
:express:clock: Clock appears to be running at 40% real time.
:express:clock(debug): Will report time scale, now 45.3109%, tod_age = 3, time_age = 1.35933, ratio = 1.10061
:express:clock: Clock appears to be running at 40% real time.
:express:clock(debug): Will report time scale, now 50.9182%, tod_age = 3.01563, time_age = 1.5355, ratio = 0.895389
:express:clock(debug): Will report time scale, now 56.6528%, tod_age = 3.01563, time_age = 1.70844, ratio = 0.898776
:express:clock(debug): Will report time scale, now 62.9766%, tod_age = 3, time_age = 1.8893, ratio = 0.899585
:express:clock(debug): Will report time scale, now 70.2042%, tod_age = 3, time_age = 2.10613, ratio = 0.897049
:express:clock(debug): Will report time scale, now 63.7783%, tod_age = 3.03125, time_age = 1.93328, ratio = 1.10075
:express:clock(debug): Will report time scale, now 57.8425%, tod_age = 3.03125, time_age = 1.75335, ratio = 1.10262
:express:clock(debug): Will report time scale, now 52.2232%, tod_age = 3.01563, time_age = 1.57485, ratio = 1.1076
:express:clock(debug): Will report time scale, now 47.2664%, tod_age = 3, time_age = 1.41799, ratio = 1.10487

That’s over the space of about ten seconds. Not sure how normal that is.

GL and DX9 display modes produce roughly equivalent results.

Forcing vsync off fixes things! It also makes the clock debug spew go away entirely. I’m going to update my drivers and see if that helps.

7

Driver update fixed this. (GeForce 6800 Ultra, XP-64, not sure what the older version was, but the new version was 190.62.)