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

multithreading java

2022-08-31 08:39:38

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

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

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

答案 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

更新

在性能分析阶段，从未见过变量等于 0。这就是为什么投机性地优化了这个分支，以便循环转换为类似的东西。iC2

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

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

过了一段时间，包裹回，这个不常见的陷阱被拿走了。该方法已取消优化，并在解释器中继续执行。在用新知识重新编译时，认识到无限循环并放弃了编译。该方法的其余部分在解释器中以适当的安全点进行。i0C2

Nitsan Wakart有一篇很棒的必读博客文章“安全点：意义，副作用和开销”，涵盖了安全点和这个特定问题。

众所周知，在很长的计数循环中消除安全点是一个问题。错误JDK-5014723（感谢弗拉基米尔·伊万诺夫）解决了这个问题。

在 Bug 最终修复之前，解决方法一直可用。

您可以尝试使用 -XX：+UseCountedLoopSafepoints（这将导致整体性能下降，并可能导致 JDK-8161147 崩溃）。使用它后，编译器继续在后跳时保留安全点，原始暂停完全消失。C2
您可以使用
-XX:CompileCommand='exclude,binary/class/Name,methodName'
或者，您可以通过手动添加安全点来重写代码。例如，在周期结束时调用甚至更改为（谢谢，Nitsan Wakart）也会修复暂停。Thread.yield()int ilong i

答案 2

简而言之，你拥有的环路内部没有安全点，除非到达。当编译此方法并触发要替换的代码时，它需要将所有线程带到一个安全点，但这需要很长时间，不仅锁定运行代码的线程，而且锁定JVM中的所有线程。i == 0

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

-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 资源。