user3789763
user3789763

Reputation: 3

Why elapsed time computed over large time windows have up to 100+milli second difference between System.currentTimeMillis vs System.nanoTime

I am trying to create a KSUID with microsecond precession sortable within same JVM, as currentTimeMillis give only Millisecond accuracy, thought of using currentTimeMillis() and nanoTime() together, collecting both the values on first instant and from second instant onwards using nanoTime difference to compute elapsed microseconds since first Instant of time. Using Elapsed time computed from nanoTime and adding it to initial Instant millis so that we can compute Epoch with microsecond accuracy for any Instant of time after JVM startup(all within same JVM).

//statically collected initial nanoTime and currentMillis final long initTimeNanos = System.nanoTime(); final long initTimeMillis = System.currentTimeMillis();

//From here on when ever current time is needed at micro/nano second precision, computing elapsed time from nanoTime and adding elapsed millis to initialMillis and rest of the elapsed time gives microsecond precision time

final long elapsedNanoTime = System.nanoTime() - initTimeNanos; final double elapsedMillisFromNanoTime = elapsedNanos / (1000000.0);

//Monotonically increasing Timestamp millis(Epoch, we may not call this Epoch) since JVM start final long computedCurrentTimeMillis = initTimeMillis + elapsedMillisFromNanoTime; final long nanosPrecision = elapsedNanos % 1000000; //additional time precision from nanoTime

Thought of using these values to generate monotonically increasing KSUID's which can approximately represent current time, but guaranteed to be ordered based on creation time within same JVM, as currentTimeMillis don't provide monotonically increasing timestamp guarantee, thought of using this approach to generate monotonically increasing timestamp that is approximately near to real time stamp(may be few millis difference unless there is a leap second adjustment to epoch time). Expected couple of milli seconds variance of elapsed time computed with epoch and nanoTime, but the real variance is very frequently changing and observed up to 150 milli second variance between these two when I ran below test for 48 hours. Majority cases elapsed time calculated with nanoTime is higher than elapsed time computed with currentTimeMillis and it's observed from -2 milliseconds to +150 milli seconds.

final long elapsedMillis = System.currentTimeMillis() - initTimeMillis;//elapsed time millis from System.currentTimeMillis() final double varianceMillis = elapsedMillisFromNanoTime - elapsedMillis; //elapsed time varience

Am I missing anything about JVM time guarantees, is it wrong way to calculate monotonically increasing approximate timestamp?(This will not be used as real Epoch in the system, only used for generating UUID's which also represent approximate timestamp Instant within same JVM).

//Test class

package org.example;

import java.util.concurrent.TimeUnit;

public class Main {
    public static void main(String[] args) throws Exception {
        final long initTimeNanos = System.nanoTime();
        final long initTimeMillis = System.currentTimeMillis();
        System.out.println("Nanos: " + initTimeNanos);
        System.out.println("Millis: " + initTimeMillis);

        while (true) {
            final long currentNanos = System.nanoTime();
            final long elapsedNanos = currentNanos - initTimeNanos;
            final double elapsedMillisFromNanos = elapsedNanos / 1000000.0;
            final long elapsedMillis = System.currentTimeMillis() - initTimeMillis;
            final double varianceMillis = elapsedMillisFromNanos - elapsedMillis;
            if (Math.abs(varianceMillis) > 1) {
                System.out.printf("\nVariance Observed: %.6f\n", varianceMillis);
                System.out.printf("Elapsed Time: %.6fms (from System.nanoTime)\n", elapsedMillisFromNanos);
                System.out.printf("Elapsed Time: %dms (from System.currentTimeMillis)\n", elapsedMillis);
            }
            if (elapsedMillis > TimeUnit.HOURS.toMillis(48)) {
                break;
            }
            Thread.sleep(5000);
            System.out.print(".");
        }
    }
}

Why elapsed time variance is continuously changing? how much of maximum varience we can expect if JVM runs continuously for an year(any JVM gurantees on this for upper or lower bounds, used MAC and windows for test, MAC gave slow increase in varience, windows was much faster)?

I was expecting elapsed time varience of less than 10 milliseconds, less frequently changing varience. But actual observation was continuously changing varience, going up and down with max of 150 milliseconds observed in 48 hours

Upvotes: 0

Views: 92

Answers (2)

Basil Bourque
Basil Bourque

Reputation: 338604

The Answer by rzwitserloot is correct. I’ll give you my take on various issues.

currentTimeMillis unrelated to nanoTime

System.currentTimeMillis and System.nanoTime have nothing to do with one another.

  • currentTimeMillis retrieves the current date and time-of-day from the hardware clock unit of the host computer, as managed by the host operating system.
  • nanoTime comes from a count kept by the CPU of the host computer.

currentTimeMillis

So the first is aware of the human concepts of year-month-day and hour-minute-second. The clock hardware used in conventional computers are limited in their resolution, some milliseconds, some microseconds, but none in nanoseconds.

The date and time reported by this call may vary, for various reasons. One such reason is computers starting up with a dead battery will have their clock reset to a default moment until corrected by a call to a time server. Another reason is that a sysadmin or user may change the date-time. Yet another reason is that the hardware clock may not keep time well, and will run fast or slow between updates by a call to a time server.

nanoTime

The nanoTime call tells elapsed time as a count of nanoseconds. But this elapsed time has nothing to do with calendars and clock-on-the-wall. This call simply returns a monotonic count of passing nanoseconds.

This count is quite accurate, as it comes from the “beating heart” of the computer. The number returned is always increasing, until reaching its limit of Long.MAX_VALUE, then wrapping around to Long.MIN_VALUE. This give a range of about 292 years, but that does not mean 292 years from now. The starting point of the count is unspecified. On some implementations of Java, you may see the count start when the computer boots. But there is no guarantee of that.

Issues

trying to create a KSUID

You might consider instead finding an implementation of the new 6, 7, 8 Versions of UUID being proposed to the IETF for standardization.

currentTimeMillis give only Millisecond accuracy

currentTimeMillis has been supplanted in modern Java by the java.time.Instant class. Call Instant.now to capture the current moment as seen in UTC.

Common implementations in Java 9+ report in microseconds, but milliseconds in Java 8. The Instant class is capable of nanoseconds.

Using Elapsed time computed from nanoTime and adding it to initial Instant millis so that we can compute Epoch with microsecond accuracy for any Instant of time after JVM startup(all within same JVM).

Clever idea. But not realistic. As discussed above, currentTimeMillis and nanoTime are unrelated. On top of that, the results of currentTimeMillis can vary for a variety of reasons. Meanwhile, the nanoTime count may well vary upon each bootup of the host computer, and certainly will not correspond to any nanoTime calls made on other machines.

Am I missing anything about JVM time guarantees

Yes, you are missing the fact that the Java specifications make none of the guarantees you seem to have assumed.

The only guarantee made in the Javadoc is that nanoTime is “high resolution”, at least as good as currentTimeMillis. And no guarantee is made regarding when you might expect to hit the 292 year wraparound.

Meanwhile, currentTimeMillis is a moving target, able to change at any moment, shifting forward or backward.

how much of maximum varience we can expect if JVM runs continuously for an year

That is unpredictable.

any JVM gurantees on this for upper or lower bounds

The Java specifications make no such guarantees.

Upvotes: 2

rzwitserloot
rzwitserloot

Reputation: 102903

One explanation is NTP based time smear. More generally nanotime and cTM measure completely different things and you cannot mix them.

nanotime has an arbitrary 0-point (getting a nanoTime of 0 has no particular meaning), and hence, there is no point to calling it at all, except for comparing what it returns to the result of a different nanoTime call. nanoTime tracks elapsed time, that's it.

System.cTM fetches the system clock. If you edit your system's time settings such as with the posix date command, or in your system settings, that has no effect on nanoTime, but changes what System.cTM returns. cTM also generally much slower than nanoTime is. cTM also has a well defined 0 - that means UTC 1970 midnight jan 1st.

The question: "I want the current time as per the system clock with nano second precision" is not possible on JVMs.

Time smear is where some network time daemon notices your system clock is slightly off and instead of just editing your system clock to the right time, a smear is introduced: Say you're 400 milliseconds 'ahead' of real time. The NTP could just set your clock 400 millis backwards, but many logging systems assume that System.cTM doesn't go backwards (an incorrect, but widely applied, assumption).

This can be 'fixed' by instead having time tick slower for a while: Every 100 milliseconds that pass, the NTP daemon 'holds' the clock on the same millis for a millisecond. This catches up 1 milli per 100, so in 400,000 millis (only 400 seconds), the clock is back in sync with the network and no logging is affected at all.

However, that would, obviously, completely ruin any relationship between System.cTM and nanoTime!

Most NTPs smear like this (they also smear forward - if your sys clock is behind it doesn't just jump ahead: That makes logs lie (making it seem like some gap between 2 events is much larger than it really was), so then every 100 millis the NTP makes the clock skips a milli, something like that, to catch up.

... but I need monotonically increasing timestamps!

Then nanoTime is irrelevant. Do not use that.

Have some centralized 'store' that provides IDs. One implementation:

class TimeStore {
  long lastVal = 0L;

  public synchronized long get() {
    long mark = System.currentTimeMillis() << 4;
    return lastVal = Math.max(mark, lastVal + 1);
  }
}

This will return the current time, shifted left by 4 bits, and will fill the 16 values that this shifting 'frees up' to be capable of generating monotonically increasing values at the identical time up to 16 times; any further request in the same millisecond would sneak into the next millisecond.

This probably isn't slower than nanoTime, synchronized notwithstanding.

Upvotes: 3

Related Questions