【发布时间】:2017-04-07 15:21:01
【问题描述】:
下面的短代码隔离了问题。基本上我正在计时方法addToStorage。我从执行一百万次开始,我能够将它的时间缩短到大约 723 纳秒。然后我做了一个短暂的暂停(使用忙碌的旋转方法不释放 cpu 核心)并在不同的代码位置再次对该方法计时 N 次。令我惊讶的是,我发现 N 越小,addToStorage 延迟越大。
例如:
If N = 1 then I get 3.6 micros
If N = 2 then I get 3.1 and 2.5 micros
if N = 5 then I get 3.7, 1.8, 1.7, 1.5 and 1.5 micros
有谁知道为什么会发生这种情况以及如何解决它?我希望我的方法在尽可能快的时间内始终如一地执行,无论我在哪里调用它。
注意:我认为这与线程无关,因为我没有使用Thread.sleep。我还测试了使用taskset 将我的线程固定到 cpu 内核,结果相同。
import java.util.ArrayList;
import java.util.List;
public class JvmOdd {
private final StringBuilder sBuilder = new StringBuilder(1024);
private final List<String> storage = new ArrayList<String>(1024 * 1024);
public void addToStorage() {
sBuilder.setLength(0);
sBuilder.append("Blah1: ").append(System.nanoTime()).append('\n');
sBuilder.append("Blah2: ").append(System.nanoTime()).append('\n');
sBuilder.append("Blah3: ").append(System.nanoTime()).append('\n');
sBuilder.append("Blah4: ").append(System.nanoTime()).append('\n');
sBuilder.append("Blah5: ").append(System.nanoTime()).append('\n');
sBuilder.append("Blah6: ").append(System.nanoTime()).append('\n');
sBuilder.append("Blah7: ").append(System.nanoTime()).append('\n');
sBuilder.append("Blah8: ").append(System.nanoTime()).append('\n');
sBuilder.append("Blah9: ").append(System.nanoTime()).append('\n');
sBuilder.append("Blah10: ").append(System.nanoTime()).append('\n');
storage.add(sBuilder.toString());
}
public static long mySleep(long t) {
long x = 0;
for(int i = 0; i < t * 10000; i++) {
x += System.currentTimeMillis() / System.nanoTime();
}
return x;
}
public static void main(String[] args) throws Exception {
int warmup = Integer.parseInt(args[0]);
int mod = Integer.parseInt(args[1]);
int passes = Integer.parseInt(args[2]);
int sleep = Integer.parseInt(args[3]);
JvmOdd jo = new JvmOdd();
// first warm up
for(int i = 0; i < warmup; i++) {
long time = System.nanoTime();
jo.addToStorage();
time = System.nanoTime() - time;
if (i % mod == 0) System.out.println(time);
}
// now see how fast the method is:
while(true) {
System.out.println();
// Thread.sleep(sleep);
mySleep(sleep);
long minTime = Long.MAX_VALUE;
for(int i = 0; i < passes; i++) {
long time = System.nanoTime();
jo.addToStorage();
time = System.nanoTime() - time;
if (i > 0) System.out.print(',');
System.out.print(time);
minTime = Math.min(time, minTime);
}
System.out.println("\nMinTime: " + minTime);
}
}
}
执行:
$ java -server -cp . JvmOdd 1000000 100000 1 5000
59103
820
727
772
734
767
730
726
840
736
3404
MinTime: 3404
【问题讨论】:
-
我只能想到CPU缓存未命中,JVM本身不会发生这种情况。
-
好点@JornVernee!对于 CPU 缓存未命中来说,差异不是太大了吗?此外,在第二次或第三次调用中,CPU 是否应该缓存它需要的内容?我们将如何进一步探索该假设?
-
差异似乎不大,内存提取最多可能需要 1000 个 ALU 周期。这真的取决于你在什么 CPU 上运行,我不知道有什么方法可以测试它(也许在恢复之前转储 CPU 缓存,如果这可能取决于你的 CPU,而不是 Java)。
-
请不要cross-post:softwareengineering.stackexchange.com/q/345768/1352“交叉发帖不受欢迎,因为它会导致零散的答案散布在整个网络。”
-
您在分析中混入了非技术语义。您的代码中没有“暂停”。线程在执行
mySleep时很忙,只有您希望将其视为睡眠操作。将方法命名为mySleep也没有真正的目的,这与 JVM 无关。因此,由于代码中没有暂停,因此它也不会“暂停后变慢”。
标签: java jvm real-time latency hotspot