Search code examples
javatiming

Java, sometimes I read a negative difference between two System.currentTimeMillis()


On a jogl sample of mine, I am having some performances issue.

I would like to profile it on the cpu side and I am using System.currentTimeMillis().

This is the main loop of my application:

    @Override
    public void display(GLAutoDrawable glad) {

    frameTimer.stop();

    frameDelta = frameTimer.getTime();

    // just an estimate
    totalTime += frameDelta;

    transformer.update(frameDelta);

    frameTimer.reset();

    GL4 gl4 = glad.getGL().getGL4();

    frameTimer.start();

    draw(gl4);

    checkGlError(gl4);

    glad.swapBuffers();
}

frameDelta is a class that has the following methods:

    private long startTime;
    private long diffTime;
    private boolean running;


    public NvStopWatch() {
        running = false;
    }

    /**
     * Start time measurement.
     */
    public void start() {
        startTime = System.currentTimeMillis();
        running = true;
    }

    /**
     * Stop time measurement.
     */
    public void stop() {
        diffTime = getDiffTime();
        running = false;
    }

    /**
     * Reset time counters to zero.
     */
    public void reset() {
        diffTime = 0;
        if (running) {
            start();
        }
    }

    public float getTime() {
        float ms = running ? getDiffTime() : diffTime;
        return ms / 1000;
    }

    /**
     * Get difference between start time and current time.
     *
     * @return
     */
    private long getDiffTime() {
        long now = System.currentTimeMillis();
        long diff = now - startTime;
        if (diff < 0) {
            System.out.println("diff " + diff + " now " + now + " startTime " + startTime);
            diff = (long) BindlessApp.minimumFrameDeltaTime;
        }
        return diff;
    }

As you see the calling order of its methods is .stop(), .getTime(), .reset() and .start()

Sometimes, on the .getTime() it happens that a negative value is returned.. just randomly without any schema or something

How could it be possible?

Edit: I did some test on windows 7 x64 (without any volatile, synchronized and nanoTime()), I dont get any negative delta over there.. only on ubuntu 15.04 x64..

Anyway unfortunately on Ubuntu volatile and synchronized don't help, nanoTime() instead does.

Do you have a valid explanation to that? Something wrong with the java implementation? I am using the one of webupd8team, 8u45.


Solution

  • This can happen when a background task updates the time, perhaps in an attempt to correct it for drift.

    You can rely on System.nanoTime to not go backwards.

    To quote System.nanoTime()

    The value returned represents nanoseconds since some fixed but arbitrary time (perhaps in the future, so values may be negative).