Timer on steroids?

[EgonOlsen]

Hi,

i've a problem similar to this one ( http://lwjgl.org/forum/index.php/topic,1955.0.html ), but hence there was no solution posted in this thread, i'll post it anyway:
There is this little Ticker-class that uses the LWJGL-Timer. On my Core2, AthlonXP and Athlon64, the timing is correct. On two P4s (one with, one without HT) that i've tried, the whole thing runs twice as fast as it should. I tried to create a test case, but in this test case, everything was fine. So i assume that it has something to do with the heavier load of the actual application or a Display being created or...
Changing the code to use System.nanoTime() (or currentTimeMillis()) and the timing is fine on both P4s. Any ideas?

P.S.: No dynamic clock speed adjustment is enabled on any of these machines...they all run at full speed all the time.

[EgonOlsen]

*Bump* No ideas? 

[Matzon]

I've never seen it... I guess there must be some issues with the timer used on some systems. However the timer we use, is the same a quake uses, so I would think that it was good enough?

It would be lovely if someone could reproduce it, debug it and test it - come up with a better solution.
We stopped using the old timer because it was based on the frequency of the cpu, which could change. however there appears to be some issues with the new timer too.......

[Matzon]

just for the record, not implying you should do it - just someone else than me, since I can't reproduce it at all

[EgonOlsen]

Ok, i'll make the "game" (it's not meant to be a real game, just an example for jPCT) a test case once it's done. This can take some weeks though. Until then, i'll work with System.nanoTime() instead of the LWJGL-timer.

[princec]

Egon - do my games run OK on your system? In windowed mode they are locked down to 60Hz by the LWJGL timer alone. If they run at 60Hz on your machine that would imply that you are probably doing something wrong in your code somewhere without realising it.

Cas

[erikd]

I've had the same problem too, the game running twice as fast because of faulty timing.
The strange thing I noticed is that timing using LWJGL running on java 1.4 was correct, but became faulty when running on 1.5 and onwards. A bit strange that the java version seems to have an influence on the LWJGL timer...

In my case, what I did notice is that the problem only seems to occur if vblanks are missed, for example when I set the display to 100Hz to render 50fps.
When running 60fps on a 60Hz display, I don't have any problem with any java version.
In my case, the error only occurs with the LWJGL timer in combination with java >= 1.5, not with the nano timer or System.currentTimeMillis.

Unfortunately I still haven't been able to reproduce the problem in a small test case... 

EgonOlson: do you also have the problem when running on 1.4 and does missing vblanks have an influence in your case too?

[EgonOlsen]

@princec: Your games run fine and so does Paradroidz when using the LWJGL timer. I would love to spot an error in my code, but unfortunately, i can't...

@ericd: No, 1.4 doesn't make a difference...but the Server-VM does!!! When running with the Java6 server-VM, the LWJGL-timer is fine. When running with the client VM, it's on steroids. I'm not sure about the vertical blank or how i should test this. I'm just creating a Ticker that ticks every 20ms (or 30ms...or 40ms...it doesn't matter, the problem stays the same). But like you, i'm not able to create a test case that shows the problem albeit i've tried a lot of things (simulate cpu load, create a Display...). However, i've enhanced my Ticker-class to show both timings like so:

package feud.testgame;

import org.lwjgl.util.*;

public class Ticker {
    private int rate;
    private long s,s2;
    private Timer timer = null;

    public Ticker(int tickrateMS) {
        rate = tickrateMS;
        timer = new Timer();
        timer.tick();
        s = (long) (timer.getTime() * 1000f);
        s2 = System.nanoTime()/1000000L;
    }

    public int getTicks() {
        long i = System.nanoTime()/1000000L;
        if (i - s2 > rate) {
            int ticks = (int) ((i - s2) / (long) rate);
            s2 += rate * ticks;
            System.out.println(ticks+"/"+getTicksLWJGL());
            return ticks;
        }
        return 0;
    }
    
    public int getTicksLWJGL() {
        timer.tick();
        long i = (long) (timer.getTime() * 1000f);
        if (i - s > rate) {
            int ticks = (int) ((i - s) / (long) rate);
            s += rate * ticks;
            return ticks;
        }
        return 0;
    }
}

The method called by my app to do the timing is getTicks() (with a Ticker initialized with 20), which itself calls getTicksLWJGL() and prints both values to the console. On the Core2, Athlon64 and AthlonXP machines (not implying that it's a cpu related problem), these values are in sync, i.e. 1/1 or 2/2...just like it is supposed to be. On the P4, i'm getting 1/2, 1/3, 2/4 etc...
Is anything wrong with my usage of Timer here? I mean whatever the rest of the code does...here, in this small class, the timings should be the same, don't they?
And remember that this doesn't happen when i'm using the class in a test case. Just when using it ingame. And just with the client VM. I'm stuck here...

[erikd]

Your problem looks remarkably the same as mine.
I just checked, but running 1.6 server indeed fixes things here too.

I suspect (I have to do some testing), that my point about missing the vblank is a red herring because when I first encountered it, the fps counter was always using System.currentTimeMillis, and I'm trying to force vsync so 60Hz with 60fps works fine even if timing is wrong.

Recently, I started measuring the fps counter with LWJGL (I basically moved all timing to a new helper class) and since then I get wrong values in the fps counter (showing about ~35 fps when it's clearly a rock-steady 60), whatever screenmode or target FPS. This is when I do throttling using System.nanoTime, and the fps counter implemented with LWJGL timer. When I throttle using LWJGL too (and with vblank disabled) it shows the requested FPS, but everything runs too fast...

I basically tried the same things as you in my test case but, like you, the problem only manifests itself in-game and with particular JVM's.

Another thing is that I had this problem with an older build of my program too, and then it magically disappeard when I inserted a Sys.getTimerResolution(), which was totally weird since it just returns a hardcoded '1000'. Maybe this line somehow just triggered the JVM to not screw up?..
The problem recently resurfaced though, and calling getTimerResolution (as to be expected) didn't make a difference.

My gut feeling is that there's a wrong optimization being done in the JVM somewhere, which typically causes LWJGL timing to fail, but I have no real evidence to back this up.
Still trying to construct a simple test case though...

[erikd]

Yay, hold the press!

It turned out that my current build didn't have Sys.getTimerResolution used in the throttling code (as opposed to what I stated in my previous post), but had a hardcoded '1000' there (again, somehow).
Replaced the 1000 with Sys.getTimerResolution() and the problem, weird as it is, magically disappeared again!

[darkprophet]

erickd, that sounds awfully weird, since WindowsSystemImplementation has 1000 hardcoded in there, so does the DefaultSysImplementation that both linux and macosx implementations extend from...

DP

[princec]

Beginning to look suspiciously like a VM bug...

Cas

[erikd]

Yes, I'm pretty much convinced it's a VM bug, especially because it works okay on certain VMs.

[Kylearan]

Hi,

sorry for the off-topic post, but...

@princec: Your games run fine and so does Paradroidz

Paradroidz?!? That sounds like...can it be... 

*googles for Paradroidz, plays game*

Indeed, it's Paradroid - and a very well done version, too! 

I love you. 

-Kylearan

[EgonOlsen]

I love you. 

At your service!