System.nanoTime和System.currentTimeMillis的区别

Question

System.nanoTime和System.currentTimeMillis的区别

7

根据其文档，System.nanoTime返回自某个固定但任意起始时间以来的纳秒数。然而，在我尝试下面代码的所有x64机器上，都存在时间跳跃，使得固定的起始时间发生了变化。可能是我使用另一种方法（这里是currentTimeMillis）获取正确时间的方法存在缺陷。然而，测量相对时间（持续时间）的主要目的也受到了负面影响。

我遇到了这个问题，当比较不同队列与LMAX的Disruptor时，我有时会得到非常负面的延迟。在这些情况下，开始和结束时间戳是由不同的线程创建的，但延迟是在这些线程完成后计算的。

我的代码使用nanoTime获取时间，使用currentTimeMillis时间计算固定的起始时间，并在调用之间比较该起始时间。既然我必须在这里提出一个问题：这段代码有什么问题？为什么它观察到违反“固定起始时间”合同的情况？或者它没有？

import java.text.*;

/**
 * test coherency between {@link System#currentTimeMillis()} and {@link System#nanoTime()}
 */
public class TimeCoherencyTest {

    static final int MAX_THREADS = Math.max( 1, Runtime.getRuntime().availableProcessors() - 1);
    static final long RUNTIME_NS = 1000000000L * 100;
    static final long BIG_OFFSET_MS = 2;

    static long startNanos;
    static long firstNanoOrigin;
    static {
        initNanos();
    }

    private static void initNanos() {
        long    millisBefore = System.currentTimeMillis();
        long    millisAfter;
        do {
            startNanos = System.nanoTime();
            millisAfter = System.currentTimeMillis();
        } while ( millisAfter != millisBefore);
        firstNanoOrigin = ( long) ( millisAfter - ( startNanos / 1e6));
    }

    static NumberFormat lnf = DecimalFormat.getNumberInstance();
    static {
        lnf.setMaximumFractionDigits( 3);
        lnf.setGroupingUsed( true);
    };

    static class TimeCoherency {
        long    firstOrigin;
        long    lastOrigin;
        long    numMismatchToLast = 0;
        long    numMismatchToFirst = 0;
        long    numMismatchToFirstBig = 0;
        long    numChecks = 0;

        public TimeCoherency( long firstNanoOrigin) {
            firstOrigin = firstNanoOrigin;
            lastOrigin = firstOrigin;
        }
    }

    public static void main( String[] args) {
        Thread[]    threads = new Thread[ MAX_THREADS];
        for ( int i = 0;  i < MAX_THREADS;  i++) {
            final int   fi = i;
            final TimeCoherency tc = new TimeCoherency( firstNanoOrigin);
            threads[ i] = new Thread() {
                @Override
                public void run() {
                    long    start = getNow( tc);
                    long    firstOrigin = tc.lastOrigin;    // get the first origin for this thread
                    System.out.println( "Thread " + fi + " started at " + lnf.format( start) + " ns");
                    long    nruns = 0;
                    while ( getNow( tc) < RUNTIME_NS) {
                        nruns++;
                    }
                    final long  runTimeNS = getNow( tc) - start;
                    final long  originDrift = tc.lastOrigin - firstOrigin;
                    nruns += 3; // account for start and end call and the one that ends the loop
                    final long skipped = nruns - tc.numChecks;
                    System.out.println( "Thread " + fi + " finished after " + lnf.format( nruns) + " runs in " + lnf.format( runTimeNS) + " ns (" + lnf.format( ( double) runTimeNS / nruns) + " ns/call) with"
                            + "\n\t" + lnf.format( tc.numMismatchToFirst) + " different from first origin (" + lnf.format( 100.0 * tc.numMismatchToFirst / nruns) + "%)"
                            + "\n\t" + lnf.format( tc.numMismatchToLast) + " jumps from last origin (" + lnf.format( 100.0 * tc.numMismatchToLast / nruns) + "%)"
                            + "\n\t" + lnf.format( tc.numMismatchToFirstBig) + " different from first origin by more than " + BIG_OFFSET_MS + " ms"
                                    + " (" + lnf.format( 100.0 * tc.numMismatchToFirstBig / nruns) + "%)"
                            + "\n\t" + "total drift: " + lnf.format( originDrift) + " ms, " + lnf.format( skipped) + " skipped (" + lnf.format( 100.0 * skipped / nruns) + " %)");
                }};
            threads[ i].start();
        }
        try {
            for ( Thread thread : threads) {
                thread.join();
            }
        } catch ( InterruptedException ie) {};
    }

    public static long getNow( TimeCoherency coherency) {
        long    millisBefore = System.currentTimeMillis();
        long    now = System.nanoTime();
        if ( coherency != null) {
            checkOffset( now, millisBefore, coherency);
        }
        return now - startNanos;
    }

    private static void checkOffset( long nanoTime, long millisBefore, TimeCoherency tc) {
        long    millisAfter = System.currentTimeMillis();
        if ( millisBefore != millisAfter) {
            // disregard since thread may have slept between calls
            return;
        }
        tc.numChecks++;
        long    nanoMillis = ( long) ( nanoTime / 1e6);
        long    nanoOrigin = millisAfter - nanoMillis;
        long    oldOrigin = tc.lastOrigin;
        if ( oldOrigin != nanoOrigin) {
            tc.lastOrigin = nanoOrigin;
            tc.numMismatchToLast++;
        }
        if ( tc.firstOrigin != nanoOrigin) {
            tc.numMismatchToFirst++;
        }
        if ( Math.abs( tc.firstOrigin - nanoOrigin) > BIG_OFFSET_MS) {
            tc.numMismatchToFirstBig ++;
        }
    }
}

现在我做了一些小改动。基本上，我在两个currentTimeMillis调用之间加入nanoTime调用的括号，以查看线程是否已被重新调度（这应该需要比currentTimeMillis分辨率更长的时间）。在这种情况下，我忽略循环周期。实际上，如果我们知道nanoTime足够快（如Ivy Bridge等新架构），我们可以将currentTimeMillis与nanoTime配对使用。

现在长时间大于10毫秒的跳跃已经消失了。相反，我们计算当每个线程距离第一个起点超过2ms时。在我测试的机器上，对于运行时间为100s，总会有接近200,000次调用之间的跳跃。正是针对这些情况，我认为currentTimeMillis或nanoTime可能不准确。

- Ralf H

非常有趣的问题。 - Jon Kiparsky

期望所有调用的起点都完全相同是不合理的 - 毕竟，您正在调用两种方法...在这两个调用之间可能存在不同的时间长度，每次调用该对。 - Jon Skeet

@JonSkeet 这也是我在答案中所说的。他多次调用偏移量。 - Meno Hochschild

System.nanoTime是原始系统时钟，使用可用的最高分辨率。它基本上是操作系统提供的任何内容。currentTimeMillis是系统时间“清理”一下以具有一致的基础。但两者都取决于操作系统。鉴于现代多处理器的现实情况，线程之间可能会有一些差异。Java无法做得比其所使用的更好。 - Hot Licks

这个问题有一些有趣的细节：https://dev59.com/anRB5IYBdhLWcg3wyqKo?rq=1 - Radiodef

2个回答

1

据我所知，方法System.currentTimeMillis()有时会出现跳跃，这取决于底层操作系统。我自己有时也观察到这种行为。因此，你的代码让我觉得你试图重复多次获取System.nanoTime()和System.currentTimeMillis()之间的偏移量。你应该尝试通过仅在调用System.currentTimeMillis()一次之前观察此偏移量，而不是说System.nanoTime()有时会导致跳跃。顺便说一句，我不会假装规范(javadoc描述与某个固定点相关的System.nanoTime())总是完美实现的。你可以看看discussion，在那里，多核CPU或CPU频率的变化可能会对System.nanoTime()所需的行为产生负面影响。但有一件事是肯定的。System.currentTimeMillis()更容易受到任意跳跃的影响。

- Meno Hochschild

很棒的回答。我刚刚发布了一个问题，也许你想发表一下你的意见？https://stackoverflow.com/questions/66789144/digging-deeper-into-system-currenttimemillis-how-precise-can-we-expect-it-to?noredirect=1#comment118063237_66789144 - mjs

网页内容由stack overflow 提供, 点击上面的

可以查看英文原文，
原文链接

- Radiodef · Accepted Answer

正如之前提到的那样，每次计算新的起点意味着您容易出现误差。

//                               ______ delay _______
//                              v                    v
long origin = (long)(System.currentTimeMillis() - System.nanoTime() / 1e6);
//                                                                  ^
//                                                            truncation

如果您修改程序，同时计算原点差异，您会发现它非常小。我测量的平均值约为200ns，这与时间延迟大约相符。

使用乘法代替除法（在接下来的几百年内应该没有溢出问题），您还会发现没有通过等式检查的计算源数量要大得多，约为99％。如果错误的原因是由于时间延迟，那么只有当延迟恰好与上一个时间相同时，它们才能通过。

更简单的测试是在连续调用nanoTime一定次数后累积经过的时间，并检查它是否与第一个和最后一个调用相符：

public class SimpleTimeCoherencyTest {
    public static void main(String[] args) {
        final long anchorNanos = System.nanoTime();

        long lastNanoTime = System.nanoTime();
        long accumulatedNanos = lastNanoTime - anchorNanos;

        long numCallsSinceAnchor = 1L;

        for(int i = 0; i < 100; i++) {
            TestRun testRun = new TestRun(accumulatedNanos, lastNanoTime);

            Thread t = new Thread(testRun);
            t.start();

            try {
                t.join();
            } catch(InterruptedException ie) {}

            lastNanoTime = testRun.lastNanoTime;
            accumulatedNanos = testRun.accumulatedNanos;
            numCallsSinceAnchor += testRun.numCallsToNanoTime;
        }

        System.out.println(numCallsSinceAnchor);
        System.out.println(accumulatedNanos);
        System.out.println(lastNanoTime - anchorNanos);
    }

    static class TestRun
    implements Runnable {
        volatile long accumulatedNanos;
        volatile long lastNanoTime;
        volatile long numCallsToNanoTime;

        TestRun(long acc, long last) {
            accumulatedNanos = acc;
            lastNanoTime = last;
        }

        @Override
        public void run() {
            long lastNanos = lastNanoTime;
            long currentNanos;

            do {
                currentNanos = System.nanoTime();
                accumulatedNanos += currentNanos - lastNanos;
                lastNanos = currentNanos;
                numCallsToNanoTime++;
            } while(currentNanos - lastNanoTime <= 100000000L);

            lastNanoTime = lastNanos;
        }
    }
}

那个测试确实表明源是相同的（或者至少误差是零均值）。