Java循环在循环中执行余数操作会阻塞所有其他线程-Java 学习之路

122

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

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

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

4 回答

93
在这里的所有解释之后（感谢Peter Lawrey），我们发现这个暂停的主要来源是很少到达循环内部的安全点，因此需要很长时间才能停止所有线程以进行JIT编译的代码替换 .

但我决定更深入地发现 why 很少达到安全点 . 我觉得有点混乱为什么在这种情况下 while 循环的后跳不是"safe" .

所以我尽其所能地召唤 -XX:+PrintAssembly 来帮助他们
```
-XX:+UnlockDiagnosticVMOptions \
-XX:+TraceClassLoading \
-XX:+DebugNonSafepoints \
-XX:+PrintCompilation \
-XX:+PrintGCDetails \
-XX:+PrintStubCode \
-XX:+PrintAssembly \
-XX:PrintAssemblyOptions=-Mintel
```
经过一番调查后，我发现在第三次重新编译lambda C2 编译器后，完全抛弃了内部循环中的安全点轮询 .

UPDATE

在分析阶段，变量 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"有一篇很棒的必读博客文章，涵盖了安全点和这个特殊问题 .

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

在最终修复错误之前，可以使用解决方法 .
- 您可以尝试使用-XX:+UseCountedLoopSafepoints（这将导致整体性能损失和 may lead to JVM crash JDK-8161147） . 使用后 C2 编译器继续保持后跳的安全点，原始暂停完全消失 .
- 您可以使用显式禁用有问题的方法的编译
  -XX:CompileCommand='exclude,binary/class/Name,methodName'
- 或者您可以通过手动添加安全点来重写代码 . 例如 Thread.yield() 在循环结束时调用甚至将 int i 更改为 long i （谢谢，Nitsan Wakart）也将修复暂停 .
回复于 2024-05-04T02:21:25+08:00

简而言之，除非达到 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资源 .

回复于 2024-05-04T02:21:25+08:00

5
找到了原因的答案 . 它们被称为安全点，最出名的是由于GC而发生的Stop-The-World .

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

不同的事件可能导致JVM暂停所有应用程序线程 . 这种停顿被称为世界停止（STW）暂停 . 触发STW暂停的最常见原因是垃圾收集（github中的示例），但是不同的JIT操作（示例），偏向锁撤销（示例），某些JVMTI操作等等还需要停止应用程序 . 应用程序线程可以安全停止的点称为惊讶安全点 . 该术语也经常用于指代所有STW暂停 . GC日志的启用或多或少都很常见 . 但是，这不会捕获有关所有安全点的信息 . 要完成所有操作，请使用以下JVM选项：-XX：PrintGCApplicationStoppedTime -XX：PrintGCApplicationConcurrentTime
如果您想知道明确引用GC的命名，请不要惊慌 - 打开这些选项会记录所有安全点，不只是垃圾收集暂停 . 如果您使用上面指定的标志运行以下示例（github中的源代码） .

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

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
```
注意第三个STW事件：
停止总时间：10.7951187秒
停止线程： 10.7950774 seconds

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

当JIT最终放弃等待并且结束代码处于无限循环时，STW结束 .
回复于 2024-05-04T02:21:25+08:00
26
在我自己跟踪注释线程和一些测试之后，我认为暂停是由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编译：
###排除编译：static blocking.TestBlockingThread :: infLoop
您可能会注意到我将该类放入一个名为blocking的包中
回复于 2024-05-04T02:21:25+08:00

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

4 回答

相关问题