Java线程在循环执行余数操作时会阻塞所有其他线程

Question

以下代码片段执行两个线程，一个是每秒记录一次的简单计时器，另一个是执行取余操作的无限循环：

public class TestBlockingThread {
    private static final Logger LOGGER = LoggerFactory.getLogger(TestBlockingThread.class);

    public static final void main(String[] args) throws InterruptedException {
        Runnable task = () -> {
            int i = 0;
            while (true) {
                i++;
                if (i != 0) {
                    boolean b = 1 % i == 0;
                }
            }
        };

        new Thread(new LogTimer()).start();
        Thread.sleep(2000);
        new Thread(task).start();
    }

    public static class LogTimer implements Runnable {
        @Override
        public void run() {
            while (true) {
                long start = System.currentTimeMillis();
                try {
                    Thread.sleep(1000);
                } catch (InterruptedException e) {
                    // do nothing
                }
                LOGGER.info("timeElapsed={}", System.currentTimeMillis() - start);
            }
        }
    }
}

这将得到以下结果：

[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=1004
[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=1003
[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=13331
[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=1006
[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=1003
[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=1004
[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=1004

我不明白为什么这个无限任务会阻塞其他线程长达13.3秒。我尝试过改变线程优先级和其他设置，但都没有效果。

如果您有任何建议来解决这个问题（包括调整操作系统上下文切换设置），请告诉我。

- kms333

---

@Marthin 不是垃圾收集器，而是即时编译（JIT）。使用-XX:+PrintCompilation运行后，当延迟结束时，我获得了以下输出：TestBlockingThread::lambda$0 @ 2 (24字节) 编译已跳过：平凡的无限循环（在不同层重新尝试）。 - Andreas

只更改了log调用为System.out.println，在我的系统上也能够复制这个问题。看起来像是一个调度程序的问题，因为如果在Runnable的while(true)循环中引入1毫秒的sleep，则其他线程的暂停就会消失。 - JJF

我不建议这样做，但是如果你使用"-Djava.compiler=NONE"禁用JIT，它就不会发生。 - Andreas

据说您可以为单个方法禁用JIT。请参见为特定方法/类禁用Java JIT？ - Andreas

此代码中没有整数除法。请修正您的标题和问题。 - user207421

Answer 1

在这里所有的解释之后（感谢Peter Lawrey），我们发现循环内部的安全点很少被触发，所以停止所有线程进行JIT编译代码替换需要很长时间，这是主要原因。

但我决定深入研究并找出为什么安全点很少被触发。我发现在这种情况下，while循环的回跳不是“安全”的，这让我有些困惑。

所以我使用-XX:+PrintAssembly来帮助解决这个问题。

-XX:+UnlockDiagnosticVMOptions \
-XX:+TraceClassLoading \
-XX:+DebugNonSafepoints \
-XX:+PrintCompilation \
-XX:+PrintGCDetails \
-XX:+PrintStubCode \
-XX:+PrintAssembly \
-XX:PrintAssemblyOptions=-Mintel

在进行了一些调查后，我发现在第三次编译lambda C2 后，编译器完全抛弃了循环内的安全点轮询。 更新 在分析阶段，变量i从未被看作等于0。这就是为什么C2会推测性地优化掉这个分支，使循环转化为类似以下的形式的原因。

for (int i = OSR_value; i != 0; i++) {
    if (1 % i == 0) {
        uncommon_trap();
    }
}
uncommon_trap();

请注意，最初的无限循环已被转换为带有计数器的常规有限循环！由于JIT优化在有限计数循环中消除安全点轮询，在此循环中也没有安全点轮询。

经过一段时间，i回到了0，并且触发了不常见的陷阱。该方法被取消优化，并在解释器中继续执行。在使用新知识重新编译时，C2识别出无限循环并放弃编译。该方法的其余部分在解释器中进行，具有适当的安全点。

有一篇非常必读的博客文章"Safepoints: Meaning, Side Effects and Overheads"，由Nitsan Wakart撰写，介绍了安全点和这个特定问题。

在非常长的计数循环中，安全点消除是一个已知的问题。该错误 JDK-5014723（感谢Vladimir Ivanov）解决了这个问题。

在修复此错误之前，可以使用解决方法。

1. 您可以尝试使用-XX:+UseCountedLoopSafepoints（它会导致总体性能下降并可能导致JVM崩溃JDK-8161147）。使用后，C2编译器继续在跳转后保持安全点，原始暂停完全消失。

2. 您可以通过使用-XX:CompileCommand='exclude,binary/class/Name,methodName'显式禁用有问题的方法的编译。

3. 或者您可以通过手动添加安全点来重写代码。例如，在循环结束时调用Thread.yield()，甚至将int i更改为long i（感谢Nitsan Wakart），也可以修复暂停。

- vsminkov

---

这是“如何修复”的真实答案。 - Andreas

警告：不要在生产环境中使用-XX:+UseCountedLoopSafepoints，因为它可能会导致JVM崩溃。目前最好的解决方法是手动将长循环拆分成较短的循环。 - apangin

我的上一条评论不准确。现在发生的情况完全清楚了。 在剖析阶段，i 从未为0，因此循环被推断转换为类似于 for (int i = osr_value; i != 0; i++) { if (1 % i == 0) uncommon_trap(); } uncommon_trap(); 的内容。 即一个常规的有限计数循环。一旦 i 回到0，就会触发异常陷阱，方法将被反优化并在解释器中进行处理。在使用新知识重新编译时，JIT 识别到无限循环并放弃编译。方法的其余部分在解释器中执行，具有适当的安全点。 - apangin

@apangin 是的。再次感谢您！这与我的观察完全相符。如果您能发布您的答案或编辑此答案，那将是很好的。没有您的解释，答案看起来不完整 :) - vsminkov

你可以将 i 定义为 long 而非 int，这样循环就会变成“无计数”，从而解决问题。 - Nitsan Wakart

Answer 2

简而言之，你的循环除了在达到i == 0时没有安全点。当编译此方法并触发代码替换时，需要将所有线程带到安全点，这需要很长时间，不仅会锁定运行代码的线程，还会锁定JVM中的所有线程。

我添加了以下命令行选项。

-XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime -XX:+PrintCompilation

我还修改了代码，使用了浮点数，看起来需要更长时间。

boolean b = 1.0 / i == 0;

我在输出中看到的是

timeElapsed=100
Application time: 0.9560686 seconds
  41423  280 %     4       TestBlockingThread::lambda$main$0 @ -2 (27 bytes)   made not entrant
Total time for which application threads were stopped: 40.3971116 seconds, Stopping threads took: 40.3967755 seconds
Application time: 0.0000219 seconds
Total time for which application threads were stopped: 0.0005840 seconds, Stopping threads took: 0.0000383 seconds
  41424  281 %     3       TestBlockingThread::lambda$main$0 @ 2 (27 bytes)
timeElapsed=40473
  41425  282 %     4       TestBlockingThread::lambda$main$0 @ 2 (27 bytes)
  41426  281 %     3       TestBlockingThread::lambda$main$0 @ -2 (27 bytes)   made not entrant
timeElapsed=100

注意: 要替换代码，必须在安全点停止线程。然而，在这里似乎很少达到这样的安全点（可能仅当i == 0时）。将任务更改为

Runnable task = () -> {
    for (int i = 1; i != 0 ; i++) {
        boolean b = 1.0 / i == 0;
    }
};

我看到有类似的延迟。

timeElapsed=100
Application time: 0.9587419 seconds
  39044  280 %     4       TestBlockingThread::lambda$main$0 @ -2 (28 bytes)   made not entrant
Total time for which application threads were stopped: 38.0227039 seconds, Stopping threads took: 38.0225761 seconds
Application time: 0.0000087 seconds
Total time for which application threads were stopped: 0.0003102 seconds, Stopping threads took: 0.0000105 seconds
timeElapsed=38100
timeElapsed=100

在循环中小心地添加代码，你就会得到更长的延迟。

for (int i = 1; i != 0 ; i++) {
    boolean b = 1.0 / i / i == 0;
}

获取

 Total time for which application threads were stopped: 59.6034546 seconds, Stopping threads took: 59.6030773 seconds

然而，修改代码使用一个本地方法，该方法始终具有安全点（如果它不是内置的）

for (int i = 1; i != 0 ; i++) {
    boolean b = Math.cos(1.0 / i) == 0;
}

打印

Total time for which application threads were stopped: 0.0001444 seconds, Stopping threads took: 0.0000615 seconds

注意：在循环中添加if (Thread.currentThread().isInterrupted()) { ... }可以增加一个安全点。

注意：这是在一个16核机器上发生的，因此不缺少CPU资源。

- Peter Lawrey

---

所以这是JVM的bug，对吧？其中“bug”指的是实现质量严重问题，而不是违反规范。 - usr

@vsminkov 由于缺乏安全点而能够停止世界几分钟听起来应该被视为一个bug。运行时负责引入安全点以避免长时间等待。 - Voo

@Voo 另一方面，在每个回跳点保留安全点可能会消耗大量 CPU 周期，并导致整个应用程序的性能明显降低。但我同意你的观点。在那种特定情况下，保留安全点是合理的。 - vsminkov

好的，我会尽力进行翻译。以下是需要翻译的内容：@Voo well... I always recall this picture when it comes to performance optimizations :D当涉及到性能优化时，我总是回想起这张图片 :D - vsminkov

.NET 在这里插入安全点（但 .NET 生成的代码较慢）。一种可能的解决方案是将循环分块。将其拆分为两个循环，使内部循环不检查 1024 个元素的批次，而外部循环驱动批次和安全点。从概念上将开销减少了 1024 倍，在实践中则更少。 - usr

Answer 3

我找到了为什么的答案。它们被称为安全点，最为人所知的是由于垃圾回收而发生的Stop-The-World。

请参阅以下文章：记录JVM中的Stop-The-World暂停。

Different events can cause the JVM to pause all the application threads. Such pauses are called Stop-The-World (STW) pauses. The most common cause for an STW pause to be triggered is garbage collection (example in github) , but different JIT actions (example), biased lock revocation (example), certain JVMTI operations , and many more also require the application to be stopped.

The points at which the application threads may be safely stopped are called, surprise, safepoints. This term is also often used to refer to all the STW pauses.

It is more or less common that GC logs are enabled. However, this does not capture information on all the safepoints. To get it all, use these JVM options:

-XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime

If you are wondering about the naming explicitly referring to GC, don’t be alarmed – turning on these options logs all of the safepoints, not just garbage collection pauses. If you run a following example (source in github) with the flags specified above.

阅读HotSpot术语表，它定义了以下内容：

safepoint

程序执行期间的一个点，在该点上所有GC根都已知，并且所有堆对象内容都是一致的。从全局角度看，在GC运行之前，所有线程必须在安全点上阻塞。（作为特例，运行JNI代码的线程可以继续运行，因为它们仅使用句柄。在安全点期间，它们必须阻塞而不是加载句柄的内容。）从本地角度看，安全点是代码块中的一个特定点，在该点上执行线程可能会为GC阻塞。 大多数调用站点都符合安全点的条件。 在每个安全点上都有强制性的不变量，这些不变量在非安全点上可以忽略。编译后的Java代码和C/C++代码都可以在安全点之间进行优化，但跨越安全点的优化要少一些。JIT编译器在每个安全点处生成一个GC映射。VM中的C/C++代码使用样式化的基于宏的约定（例如，TRAPS）来标记潜在的安全点。

使用上述标志运行时，我得到以下输出：

Application time: 0.9668750 seconds
Total time for which application threads were stopped: 0.0000747 seconds, Stopping threads took: 0.0000291 seconds
timeElapsed=1015
Application time: 1.0148568 seconds
Total time for which application threads were stopped: 0.0000556 seconds, Stopping threads took: 0.0000168 seconds
timeElapsed=1015
timeElapsed=1014
Application time: 2.0453971 seconds
Total time for which application threads were stopped: 10.7951187 seconds, Stopping threads took: 10.7950774 seconds
timeElapsed=11732
Application time: 1.0149263 seconds
Total time for which application threads were stopped: 0.0000644 seconds, Stopping threads took: 0.0000368 seconds
timeElapsed=1015

Please note the third STW event:
Total time stopped: 10.7951187 seconds
Stopping threads took: 10.7950774 seconds

JIT本身几乎没有花费时间，但一旦JVM决定执行JIT编译，它进入了STW模式，但由于要编译的代码(无限循环)没有调用站点，因此从未达到安全点。

当JIT最终放弃等待并得出代码处于无限循环状态时，STW结束。

- Andreas

---

"Safepoint - 程序执行期间的一个点，在该点上所有GC根已知，并且所有堆对象内容都是一致的" - 仅设置/读取本地值类型变量的循环为什么不是这样的？ - BlueRaja - Danny Pflughoeft

@BlueRaja-DannyPflughoeft 我已经在我的回答中尝试回答了这个问题。 - vsminkov

Answer 4

通过阅读评论以及自己的一些测试，我认为暂停是由JIT编译器引起的。为什么JIT编译器需要这么长时间是我无法调试的。

然而，既然您只要求如何预防这种情况，我有一个解决方案:

将您的无限循环放入一个方法中，从而可以将其排除在JIT编译器之外。

public class TestBlockingThread {
    private static final Logger LOGGER = Logger.getLogger(TestBlockingThread.class.getName());

    public static final void main(String[] args) throws InterruptedException     {
        Runnable task = () -> {
            infLoop();
        };
        new Thread(new LogTimer()).start();
        Thread.sleep(2000);
        new Thread(task).start();
    }

    private static void infLoop()
    {
        int i = 0;
        while (true) {
            i++;
            if (i != 0) {
                boolean b = 1 % i == 0;
            }
        }
    }

使用以下VM参数运行您的程序：

-XX：CompileCommand = exclude，PACKAGE.TestBlockingThread :: infLoop（将PACKAGE替换为您的包信息）

您应该会收到这样的消息，以指示何时会JIT编译该方法：
### Excluding compile: static blocking.TestBlockingThread :: infLoop
您可能会注意到，我将该类放入了一个名为blocking的包中。

- Jeutnarg

---

编译器并不需要很长时间，问题在于代码没有到达安全点，因为除了当 i == 0 时，循环内部没有其他安全点。 - Peter Lawrey

@PeterLawrey 但是为什么while循环的结束不是一个安全点？ - vsminkov

@vsminkov 看起来 if (i != 0) { ... } else { safepoint(); } 中有一个安全点，但这是非常罕见的。换言之，如果你退出/中断循环，你会得到基本相同的计时。 - Peter Lawrey

@PeterLawrey 经过一番调查，我发现在循环的后跳处设置安全点是常见做法。我只是好奇在这种特殊情况下有什么区别。也许我太天真了，但我看不出为什么后跳不是“安全”的。 - vsminkov

@vsminkov 我怀疑JIT看到循环中有一个安全点，因此不会在结尾处添加一个。 - Peter Lawrey