java中获取比毫秒更为精确的时间

关键词: java 毫秒 微秒 纳秒 System.currentTimeMillis() 误差

 

在对新写的超快xml解析器和xpath引擎进行效率测试时,为获取执行时间,开始也没多想就用了System.currentTimeMillis() 来做的。由此碰到一个极其诡异的问题,同样的代码循环执行数次,分析每一次的执行时间,发现一大部分执行时间为小于1毫秒,但其间也发现有相当一部分的执行时间有非常大的跳跃,而且时间都近似16毫秒左右。这个1毫秒和16毫秒结果,以计算机的运行速度看,差距是惊人的,必须找出其原因。

 

根据经验,在16毫秒时间内,cpu可以运算的指令数量是相当惊人的,所以可以基本断定这16ms的差距,应当不是cpu在执行指令,另外因为测试过程中gc输出也已经打开,未见gc发生,所以怀疑可能是发生了什么io阻塞,比如文件读写、加载类库、或者什么网络操作等,由于笔者测试的系统的环境比较复杂,其间有用到ehCache,数据库操作等,排查起来非常不容易。

 

在困扰了好一阵之后,忽然想到可能计时系统有误差,这才翻回来查了下System.currentTimeMillis() 的文档,原来这个方法调用了个native方法,获取的时间精度会依赖于操作系统的实现机制。奶奶的!

 

既然不准,就看看有没更准的方法,在jdk5源码中,挨着System.currentTimeMillis() 定义就是System.nanoTime() 方法,靠,一下来了个精准1000000倍的取纳秒的方法,不过看jdk文档介绍,这个方法的精度依然依赖操作系统,不过再不准也能达到微秒级的准确度,放心用吧! 结果测试结果一下准确了不少,没再发现比较大的跳跃了。

 

所以这里提醒做非常精确的时间统计的朋友,谨慎使用System.currentTimeMillis() 。

 

 

虽然用取纳秒的方法解决了我的问题,但对于为何使用System.currentTimeMillis() 会造成那么大的跳跃,一直无解,有点郁闷。幸运的是今天恰巧看到一个网友做的测试很有意思,用事实数据证明了这个跳跃的存在,分享给感兴趣的同学!

(原文链接:http://blog.csdn.net/elky1982/archive/2009/10/16/4677365.aspx

以下内容为转帖:

 

在Java中可以通过System.currentTimeMillis()或者System.nanoTime() (JDK>=5.0) 方法获得当前的时间的精确值。但是通过阅读Javadoc,我们发现这两个方法并不一定保证得到你所期望的精度。先来看System.currentTimeMillis():

Returns the current time in milliseconds. Note that while the unit of time of the return value is a millisecond, the granularity of the value depends on the underlying operating system and may be larger. For example, many operating systems measure time in units of tens of milliseconds.

诚如上面所说返回值的粒度依赖于底层操作系统,那么它在不同的平台上到底能提供是么样的精度,是否像函数名所写的那样真正 精 确到1毫秒呢?看下面一段测试程序:

 


public class ClockAccuracyTest {

    public static void main(String args[]) {

        SimpleDateFormat formatter = new SimpleDateFormat("dd-MMM-yyyy HH:mm:ss:SSS");
        int size = 4000000;

        // create an array to hold millisecond times
        // and loop to capture them
        long times[] = new long[size];
        for (int i = 0; i < size; i++) {
            times[i] = System.currentTimeMillis();
        }

        // now display the unique times
        long time = times[0];
        long previousTime = times[0];
        long count = 0;
        Set<Long> deltas = new HashSet<Long>();       
        long delta = 0;
        long minDelta = Long.MAX_VALUE;
        long maxDelta = Long.MIN_VALUE;
        for (int i = 0; i < size; i++) {
            if (times[i] > time) {
                delta = time - previousTime;
                deltas.add(delta);
                if (delta > 0 && delta < minDelta) {
                    minDelta = delta;
                } else if (delta > maxDelta) {
                    maxDelta = delta;
                }

                System.out.print("raw=");
                System.out.print(time);
                System.out.print(" | formatted=");
                System.out.print(formatter.format(new Date(time)));
                System.out.print(" | frequency=");
                System.out.print(count);
                System.out.print(" | delta=");
                System.out.print(delta);
                System.out.println("ms");

                previousTime = time;
                time = times[i];
                count = 0;
            } else {
                count++;
            }
        }

        System.out.println("");
        System.out.println("Minimum delta : " + minDelta + "ms");
        System.out.println("Maximum delta : " + maxDelta + "ms");

    }

}

 


这段程序循环调用 System.currentTimeMillis()方法, 记录并显示结果,在我机器(Windows XP SP3)上运行输出如下:

 

raw=1255659457187 | formatted=16-十月-2009 10:17:37:187 | frequency=147250 | delta=0ms
raw=1255659457203 | formatted=16-十月-2009 10:17:37:203 | frequency=447674 | delta=16ms
raw=1255659457218 | formatted=16-十月-2009 10:17:37:218 | frequency=436583 | delta=15ms
raw=1255659457234 | formatted=16-十月-2009 10:17:37:234 | frequency=439379 | delta=16ms
raw=1255659457250 | formatted=16-十月-2009 10:17:37:250 | frequency=426547 | delta=16ms
raw=1255659457265 | formatted=16-十月-2009 10:17:37:265 | frequency=447048 | delta=15ms
raw=1255659457281 | formatted=16-十月-2009 10:17:37:281 | frequency=459522 | delta=16ms
raw=1255659457296 | formatted=16-十月-2009 10:17:37:296 | frequency=414816 | delta=15ms
raw=1255659457312 | formatted=16-十月-2009 10:17:37:312 | frequency=458826 | delta=16ms

Minimum delta : 15ms
Maximum delta : 16ms

输出的四列从左到右分别是原始的毫秒值、格式化的时间、每个值循环的次数、与上一个不同值的差。可以看到在Windows上 System.currentTimeMillis()方法并不能提供1ms的计时粒度,它的粒度为15~16ms,从网上的其它文章来看,这个结果基本上是一致的,这也验证了Javadoc上所写的“ the granularity of the value depends on the underlying operating system and may be larger ”。在其他操作系统,如Linux、Solaris上,我没有进行测试,但从网上的一些测试结果看, currentTimeMillis方法在 某些操作系统能够提供精确的1毫秒计时粒度。这是不是意味着Java在Windows上无法进行精确的毫秒计时了呢?当然不是,一种解决方案是采用JNI调用,利用Windows系统提供的函数计时;还有一个更简便的办法,就是使用JDK5.0加入的System.nanoTime()方法。Javadoc对该方法的描述如下:

Returns the current value of the most precise available system timer, in nanoseconds.

This method can only be used to measure elapsed time and is not related to any other notion of system or wall-clock time. The value returned represents nanoseconds since some fixed but arbitrary time (perhaps in the future, so values may be negative). This method provides nanosecond precision, but not necessarily nanosecond accuracy. No guarantees are made about how frequently values change. Differences in successive calls that span greater than approximately 292 years (263 nanoseconds) will not accurately compute elapsed time due to numerical overflow.

它返回系统能够提供的最为精确的计时,以纳秒(10亿分之一秒)为单位,但并不保证纳秒级精度。把上面的测试程序中黑体的一行改为“times[i] = System.nanoTime();”,并把所有的“ms”该成“ns”,循环次数改为10。运行输出如下:

raw=8705892679376 | formatted=17-十一月-2245 23:31:19:376 | frequency=1 | delta=0ns
raw=8705892681053 | formatted=17-十一月-2245 23:31:21:053 | frequency=0 | delta=1677ns
raw=8705892682449 | formatted=17-十一月-2245 23:31:22:449 | frequency=0 | delta=1396ns
raw=8705892683846 | formatted=17-十一月-2245 23:31:23:846 | frequency=0 | delta=1397ns
raw=8705892685522 | formatted=17-十一月-2245 23:31:25:522 | frequency=0 | delta=1676ns
raw=8705892686919 | formatted=17-十一月-2245 23:31:26:919 | frequency=0 | delta=1397ns
raw=8705892688316 | formatted=17-十一月-2245 23:31:28:316 | frequency=0 | delta=1397ns
raw=8705892689713 | formatted=17-十一月-2245 23:31:29:713 | frequency=0 | delta=1397ns
raw=8705892691110 | formatted=17-十一月-2245 23:31:31:110 | frequency=0 | delta=1397ns

Minimum delta : 1396ns
Maximum delta : 1676ns

我们看到frequency=0,这意味着每执行一次循环,nanoTime方法的返回值都发生了改变,改变的差值平均大约为1467ns(不同性能的机器结果会不同)。这说明nanoTime方法计时的精度是非常高的,粒度比方法本身的调用执行耗时还要小。

回到上面的问题,如何在windows上实现精确的毫秒计时呢。答案就是用“System.nanoTime()/1000000L”代替“System.currentTimeInMills()”。把测试程序黑体的一行代码改为"times[i] = System.nanoTime()/1000000L;",循环次数5000,运行输出结果如下:

raw=9487129 | formatted=01-一月-1970 10:38:07:129 | frequency=202 | delta=0ms
raw=9487130 | formatted=01-一月-1970 10:38:07:130 | frequency=704 | delta=1ms
raw=9487131 | formatted=01-一月-1970 10:38:07:131 | frequency=621 | delta=1ms
raw=9487132 | formatted=01-一月-1970 10:38:07:132 | frequency=618 | delta=1ms
raw=9487133 | formatted=01-一月-1970 10:38:07:133 | frequency=696 | delta=1ms
raw=9487134 | formatted=01-一月-1970 10:38:07:134 | frequency=695 | delta=1ms
raw=9487135 | formatted=01-一月-1970 10:38:07:135 | frequency=698 | delta=1ms
raw=9487136 | formatted=01-一月-1970 10:38:07:136 | frequency=698 | delta=1ms

Minimum delta : 1ms
Maximum delta : 1ms

我们看到粒度delta变为了1ms。循环次数frequency平均为676,也就是说每个循环运运行耗时1/676=0.001479ms=1479ns,与上一个测试结果的1467ns吻合。

结论:如果你的Java程序需要高精度的计时,如1毫秒或者更小,使用System.nanoTime()方法,它完全可以满足你的需求。如果不行的话,建议你换台更快的机器试试:)

 

阅读更多
想对作者说点什么? 我来说一句

没有更多推荐了,返回首页