发现一个 Java 代码耗时统计的问题

V2EX = way to explore

V2EX 是一个关于分享和探索的地方

现在注册

已注册用户请登录

这是一个创建于 810 天前的主题，其中的信息可能已经有所发展或是发生改变。

一个方法的执行时间耗时比较高，用以下的代码统计耗时发现整个方法耗时长，但是单次循环的耗时又很小。整个方法 for 循环外没有其他代码，代码如下，某次耗时如下。并非每次都这样，但都是 cost 比 cost1 加起来要大，循环次数不会很大，1-10 次左右。环境：jdk1.8,IDEA2021

		fun(){
			long st = System.currentTimeMillis();
			for(xxx){
				long st1 = System.currentTimeMillis();
				xxxxx
				long et1 = System.currentTimeMillis();
				System.out.println("cost1:" + (et1-st1));
			}
			long et = System.currentTimeMillis();
			System.out.println("cost:" + (et-st));
		}
		cost1:16
		cost1:13
		cost1:16
		cost1:2
		cost:168

12 条回复 • 2022-09-05 15:12:58 +08:00

AlkTTT

2022-09-05 11:14:34 +08:00

System.out.println();
控制台打印是走 IO 的，也有耗时

CodeXx

2022-09-05 11:21:28 +08:00

@AlkTTT 会耗时这么高吗

fzdwx

2022-09-05 11:44:51 +08:00

@AlkTTT #1
```
long et = System.currentTimeMillis();
```
这一行已经把时间算出来了。跟`print`没关系把。

Jooooooooo

2022-09-05 11:46:29 +08:00

java 有 jit 和 gc 的, 没法这么简单的算耗时. 至少你的循环次数不够.

timethinker

2022-09-05 11:53:11 +08:00

@fzdwx 之前的时间都是单纯的计算两个时间差，并没有把每次的输出计算在内，但是最后的输出包含了循环内的 println 语句，所以总时间跟之前的时间存在悬殊。

timethinker

2022-09-05 12:02:27 +08:00

建议楼主先把计算的结果缓存到一个数组内，最后再打印出来数组内的结果，看看是否可以得到心中想要的答案，就能确定问题出在什么地方了。

chendy

2022-09-05 13:13:11 +08:00

因为有 GC ，JIT ，以及系统资源调度等等等的问题导致时间不稳定
需要做足够的 warmup ，跑比较多的次数才能得到一个相对准确的时间
测性能的话，推荐使用 jmh https://github.com/openjdk/jmh

340244120w

2022-09-05 13:42:38 +08:00 via iPhone

把 print 去掉程序最后一行再 print 看看最终结果。楼上几位说 jit 的，审题不仔细啊

yiqunz

2022-09-05 14:18:27 +08:00

··· java
public static void main(String[] args) throws InterruptedException {
int times = 10;
long[] s1 = new long[times];
long[] s2 = new long[times];
long start = System.currentTimeMillis();
for (int i = 0; i < times; i++) {
s1[i] = System.currentTimeMillis();
Thread.sleep(10);
s2[i] = System.currentTimeMillis();
}
long end = System.currentTimeMillis();
System.out.println(end - start);
long all = 0;
for (int i = 0; i < times; i++) {
System.out.println(s2[i] - s1[i]);
all += s2[i] - s1[i];
}
System.out.println(all);
}

```
实测就是相同的

yiqunz

2022-09-05 14:18:56 +08:00

``` java
public static void main(String[] args) throws InterruptedException {
int times = 10;
long[] s1 = new long[times];
long[] s2 = new long[times];
long start = System.currentTimeMillis();
for (int i = 0; i < times; i++) {
s1[i] = System.currentTimeMillis();
Thread.sleep(10);
s2[i] = System.currentTimeMillis();
}
long end = System.currentTimeMillis();
System.out.println(end - start);
long all = 0;
for (int i = 0; i < times; i++) {
System.out.println(s2[i] - s1[i]);
all += s2[i] - s1[i];
}
System.out.println(all);
}

```
实测就是相同的

CodeXx

2022-09-05 14:43:37 +08:00

感谢以上回复。本人疏忽，for 里面有些条件 continue 了，导致的时间对不上。。应该要在 for 开头打印上次执行完到这次开始执行的时间的

AS4694lAS4808

2022-09-05 15:12:58 +08:00

有 continue 不写出来不是在忽悠楼上的大神们[狗头]