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

Question

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.

At a glance it looks like you might have threading issues. Is the running variable declared as volatile? Also anytime running is accessed I see a chance for inconsistency. You may want to synchronize the start() and stop() methods to see if that changes anything. — cyber-monk, May 07 '15 at 17:36
@cyber-monk, no, then I will try to declare it as volatile and declare start() and stop() synchronized — elect, May 07 '15 at 17:41
Could be a background process that is updating your time on a regular basis. Could also consider [System.nanoTime](http://stackoverflow.com/q/510462/823393) as it will not drift backwards. — OldCurmudgeon, May 07 '15 at 17:50
When does .start() get called?, seems like getDiffTime() assumes .start() has been called — cyber-monk, May 08 '15 at 01:48
@cyber-monk `.start()` gets called just before ` draw(gl4);` — elect, May 08 '15 at 09:40

score 2 · Accepted Answer · edited May 23 '17 at 12:14

2

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).

edited May 23 '17 at 12:14

Community

1
1

answered May 08 '15 at 09:43

OldCurmudgeon

64,482
16
119
213

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

1 Answers1