Java 线程在循环中执行余数运算会阻塞所有其他线程

Posted 2023-02-26

【中文标题】Java 线程在循环中执行余数运算会阻塞所有其他线程

【英文标题】：Java thread executing remainder operation in a loop blocks all other threads

【发布时间】：2017-01-10 22:17:05

【问题描述】：

下面的代码sn-p执行两个线程，一个是简单的定时器每秒记录一次，第二个是无限循环执行余数运算：

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 秒。我尝试更改线程优先级和其他设置，但没有任何效果。

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

【问题讨论】：

@Marthin 不是 GC。这是 JIT。使用-XX:+PrintCompilation 运行时，延长延迟结束时我得到以下信息：TestBlockingThread::lambda$0 @ 2 (24 bytes) 跳过编译：普通无限循环（在不同层重试）

它在我的系统上重现，唯一的变化是我用 System.out.println 替换了日志调用。似乎是调度程序问题，因为如果您在 Runnable 的 while(true) 循环中引入 1ms 睡眠，则另一个线程中的暂停就会消失。

不是我推荐的，但是如果你使用-Djava.compiler=NONE禁用 JIT，它就不会发生。

您可以为单个方法禁用 JIT。见Disable Java JIT for a specific method/class?

这段代码中没有整数除法。请修正您的标题和问题。

【参考方案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 识别出无限循环并放弃编译。该方法的其余部分在解释器中进行，并带有适当的安全点。

Nitsan Wakart 撰写的一篇精彩的必读博文 "Safepoints: Meaning, Side Effects and Overheads" 涵盖了安全点和这个特定问题。

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

在错误最终修复之前，解决方法是可用的。

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

您可以使用-XX:CompileCommand='exclude,binary/class/Name,methodName'

显式禁用编译有问题的方法

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

【讨论】：

这是如何修复问题的真正答案。

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

@apangin 啊。知道了！谢谢:) 这就是c2 删除安全点的原因！但我没有得到的另一件事是接下来会发生什么。据我所见，循环展开后没有安全点（？），看起来没有办法做 stw.所以会发生某种超时并进行反优化？

我之前的评论不准确。现在完全清楚会发生什么。在分析阶段，i 永远不会为 0，因此循环被推测性地转换为类似for (int i = osr_value; i != 0; i++) if (1 % i == 0) uncommon_trap(); uncommon_trap(); 的东西，即一个常规的有限计数循环。一旦i 回到 0，就会采取不常见的陷阱，该方法被取消优化并在解释器中继续。在使用新知识重新编译期间，JIT 识别出无限循环并放弃编译。该方法的其余部分在具有适当安全点的解释器中执行。

您可以只将 i 设为 long 而不是 int，这样会使循环“不计数”并解决问题。

【参考方案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 资源。

【讨论】：

所以这是一个 JVM 错误，对吧？其中“错误”意味着严重的实施质量问题而不是违反规范。

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

@Voo 但另一方面，在每次后跳中保持安全点可能会花费大量 CPU 周期并导致整个应用程序的性能明显下降。但我同意你的看法。在那种特殊情况下，保持安全点看起来是合法的

@Voo 好吧...当谈到性能优化时，我总是记得this 图片：D

.NET 确实在此处插入了安全点（但 .NET 生成的代码很慢）。一个可能的解决方案是将循环分块。分成两个循环，使内部不检查 1024 个元素的批次，外部循环驱动批次和安全点。从概念上将开销减少了 1024 倍，实际上更少。

【参考方案3】：

找到为什么的答案。它们被称为安全点，最著名的是因为 GC 而发生的 Stop-The-World。

看这篇文章：Logging stop-the-world pauses in JVM

不同的事件可能会导致 JVM 暂停所有应用程序线程。这种停顿称为 Stop-The-World (STW) 停顿。触发 STW 暂停的最常见原因是垃圾收集（github 中的示例），但不同的 JIT 操作（示例）、偏向锁撤销（示例）、某些 JVMTI 操作等等要求停止应用程序。

应用程序线程可以安全停止的点被称为安全点。该术语也常用于指代所有 STW 停顿。

启用 GC 日志的情况或多或少是常见的。但是，这并不能捕获所有安全点的信息。要获得这一切，请使用以下 JVM 选项：

-XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime

如果您对明确引用 GC 的命名感到疑惑，请不要惊慌——打开这些选项会记录所有安全点，而不仅仅是垃圾收集暂停。如果您使用上面指定的标志运行以下示例（来源在 github）。

阅读HotSpot Glossary of Terms，它定义了这个：

安全点

程序执行过程中所有 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

注意第三个 STW 事件：停止的总时间： 10.7951187 秒停止线程耗时： 10.7950774 秒

JIT 本身几乎不需要任何时间，但是一旦 JVM 决定执行 JIT 编译，它就会进入 STW 模式，但是由于要编译的代码（无限循环）没有 调用站点，从未到达安全点。

当 JIT 最终放弃等待并断定代码处于无限循环中时，STW 结束。

【讨论】：

“安全点 - 程序执行期间所有 GC 根都已知且所有堆对象内容一致的点” - 为什么在只有设置/读取本地值类型变量？

@BlueRaja-DannyPflughoeft 我试图在my 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的包中

【讨论】：

编译器没有花那么长时间，问题是代码没有到达安全点，因为循环内没有任何东西，除非i == 0

@PeterLawrey 但为什么while 循环中的循环结束不是安全点？

@vsminkov 看来if (i != 0) ... else safepoint(); 中有一个安全点，但这非常罕见。 IE。如果你退出/打破循环，你会得到几乎相同的时间。

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

@vsminkov 我怀疑 JIT 看到一个安全点在循环中，所以不会在最后添加一个。