java - 在几个方法调用周围使用 System.nanoTime() 的耗时提供的值低于每个方法中耗时的总和？

Question

我正在使用 System.nanoTime() 来测量调用多个方法所花费的时间。在这些方法中的每一种中，我都会做同样的事情来测量每种方法需要多长时间。最后，耗时的总和应该小于总耗时，或者我是这么认为的。然而，事实并非如此。

例子:

public static void main(String[] args){
  long startTime = System.nanoTime();
  method1();
  method2();
  method3();
  System.out.println( "Total Time: " + (System.nanoTime() - startTime) / 1000000);
}
private void method1(){
  long startTime = System.nanoTime();
  //Stuff
  System.out.println( "Method 1: " + (System.nanoTime() - startTime) / 1000000);
}
// same for all other methods

在我的例子中，我得到的总时间约为 950 毫秒，但每个耗时的总和为 1300 毫秒以上。这是为什么？

编辑:

好吧，更清楚一点，我没有在多次写入数组时出现这种行为(我只是作为测试)。当我这样做时，我得到了非常准确的结果 (+-1ms)。

我实际做的是这样的:

我将两个相当大的文本文件读入字符串数组(第一个文件中有 1000 * ~2000 个字符，第二个文件中有 200 * ~100 个字符)。

然后我对读取第一个文件得到的字符串数组进行大量比较，并使用结果计算一些概率。

EDIT2:我的错误，我在方法中调用方法并总结了那些已经包括在内的时间。没有这些两倍，一切都会加起来。感谢您解决这个问题!

Answer 1

为了进一步研究这个东西，也许你可以打印出每个方法和全局进程的开始和结束时间。在这里你只是打印每个人花费的时间和总时间，但你可以输出这样的东西:

Global start   : (result of System.nanoTime() here)
Method 1 Start : ...
Method 1 End   : ....
Method 2 Start : ....
Method 2 End   : ....
Method 3 Start : ....
Method 3 End   : ....
Global end     : ....

我建议您这样做的原因如下:您希望 GlobalEnd - GlobalStart 大于或等于 (End1-Start1) + (End2-Start2) + (End3 -开始3)。但这种关系实际上源于这样一个事实，即如果一切都是顺序的，则以下情况成立:

GlobalStart <= Start1 <= End1 <= Start2 <= End2 <= Start3 <= End3 <= GlobalEnd

不是吗？

然后你会感兴趣的是知道在这个不等式列表中什么是不正确的。这可能会给您一些见解。