当忙于旋转的 Java 线程绑定到物理内核时,是否可以由于到达代码中的新分支而发生上下文切换?

我对低延迟代码感兴趣,这就是我尝试配置线程相关性的原因。特别是,它应该有助于避免上下文切换。

我已使用 https://github.com/OpenHFT/Java-Thread-Affinity 配置了线程关联。我运行非常简单的测试代码,只是在一个周期中旋转检查时间条件。

    long now = start;
    while (true)
    {
        if (now < start + TimeUtils.NANOS_IN_SECOND * delay)
        {
            now = TimeUtils.now();
        }
        else
        {
            // Will be printed after 30 sec
            if (TimeUtils.now() > start + TimeUtils.NANOS_IN_SECOND * (delay + 30))
            {
                final long finalNow = now;
                System.out.println("Time is over at " +
                        TimeUtils.toInstant(finalNow) + " now: " +
                        TimeUtils.toInstant(TimeUtils.now()));
                System.exit(0);
            }
        }
    }

因此,在指定的延迟执行转到“else”之后,大约同时我看到上下文切换。这是预期的行为吗?具体原因是什么?在这种情况下,如何避免上下文切换?

测试详细信息

我从这个存储库构建shadowJar:https://github.com/stepan2271/thread-affinity-example。然后我使用以下命令运行它(可以在这里玩数字,当延迟>60时,它对测试没有显着影响):

taskset -c 19 java -DtestLoopBindingCpu=3 -Ddelay=74 -cp demo-all.jar main.TestLoop

我还有以下测试脚本来监视上下文切换(应使用绑定到核心的 Java 线程的 ID 运行)

#!/bin/bash
while [ true ]
do
date >> ~/demo-ctxt-switches.log
cat /proc/$1/status | grep ctxt >> ~/demo-ctxt-switches.log
sleep 3
done

此脚本的典型输出如下:

Fri Oct 16 18:23:29 MSK 2020
voluntary_ctxt_switches:    90
nonvoluntary_ctxt_switches: 37
Fri Oct 16 18:23:32 MSK 2020
voluntary_ctxt_switches:    90
nonvoluntary_ctxt_switches: 37
Fri Oct 16 18:23:35 MSK 2020
voluntary_ctxt_switches:    90
nonvoluntary_ctxt_switches: 37
Fri Oct 16 18:23:38 MSK 2020
voluntary_ctxt_switches:    90
nonvoluntary_ctxt_switches: 37
Fri Oct 16 18:23:41 MSK 2020
voluntary_ctxt_switches:    91
nonvoluntary_ctxt_switches: 37
Fri Oct 16 18:23:44 MSK 2020
voluntary_ctxt_switches:    91
nonvoluntary_ctxt_switches: 37
Fri Oct 16 18:23:47 MSK 2020
voluntary_ctxt_switches:    91
nonvoluntary_ctxt_switches: 37

因此,在开始时间发生一些变化之后,这些数字变得稳定,然后在代码到达“else”分支时,我看到1到3个开关(差异小于1秒)。

偏差

基本配置几乎每次都会重现此行为,而一些偏差会导致我无法重现的情况。例子:

https://github.com/stepan2271/thread-affinity-example/tree/without-log4j

https://github.com/stepan2271/thread-affinity-example/tree/without-cached-nano-clock

测试环境

2 * 英特尔(R) 至强(R) 金牌 6244 CPU @ 3.60GHz

Red Hat Enterprise Linux 8.1 (Ootpa)

内核使用 /etc/systemd/system.conf 和 /etc/systemd/user.conf 中的 CPUAffinity 进行隔离

/etc/sysconfig/irqbalance is configuration.

Openjdk 11.0.6 2020-01-14 LTS 运行时环境 18.9


答案 1

自愿上下文切换通常意味着线程正在等待某些内容,例如,锁变得可用。

异步探查器可以帮助查找上下文切换发生的位置。这是我使用的命令行:

./profiler.sh -d 80 -e context-switches -i 2 -t -f switches.svg -I 'main*' -X 'exit_to_usermode_loop*' PID

让我们详细介绍一下:

  • -d 80运行探查器最多 80 秒。
  • -e context-switches要分析的事件。
  • -i 2间隔 = 2 个事件。我分析每秒钟的上下文切换,因为分析信号本身会导致上下文切换,我不想陷入递归。
  • -t按线程拆分配置文件。
  • -f switches.svg输出文件名;svg扩展自动选择火焰图格式。
  • -I 'main*'在输出中仅包含主线程。
  • -X 'exit_to_usermode_loop*'排除与非自愿上下文切换相关的事件。
  • PID要分析的 Java 进程 ID。

结果可能因运行而异。通常,我看到每个图形上有0到3个上下文切换。

Context switches 1

Context switches 2

以下是发生上下文切换的最常见位置。它们确实与等待互斥体有关。

  1. ThreadSafepointState::handle_polling_page_exception()从 调用。这意味着,一个线程已在另一个线程请求的安全点停止。要调查安全点的原因,请添加 JVM 选项。TestLoop.main-Xlog:safepoint*
[75.889s][info][safepoint        ] Application time: 74.0071000 seconds
[75.889s][info][safepoint        ] Entering safepoint region: Cleanup
[75.889s][info][safepoint,cleanup] deflating idle monitors, 0.0000003 secs
[75.889s][info][safepoint,cleanup] updating inline caches, 0.0000058 secs
[75.890s][info][safepoint,cleanup] compilation policy safepoint handler, 0.0000004 secs
[75.890s][info][safepoint,cleanup] purging class loader data graph, 0.0000001 secs
[75.890s][info][safepoint,cleanup] resizing system dictionaries, 0.0000009 secs
[75.890s][info][safepoint,cleanup] safepoint cleanup tasks, 0.0001440 secs
[75.890s][info][safepoint        ] Leaving safepoint region

右图是清理安全点在 74 秒(恰好是指定的延迟)后不久发生的。清理安全点是运行定期任务;在这种情况下 - 更新内联缓存。如果有清理工作要做,则安全点可能每毫秒发生一次(默认为 1000)。您可以通过设置 来禁用定期安全点,但这可能会影响性能GuaranteedSafepointInterval-XX:GuaranteedSafepointInterval=0

  1. SharedRuntime::handle_wrong_method()从。当已编译代码中的调用站点已设置为非进入状态时,会发生这种情况。由于这与 JIT 编译相关,因此请添加选项。TimeUtils.now-XX:+PrintCompilation
  75032 1430 %     4       main.TestLoop::main @ 149 (245 bytes)   made not entrant
  75033 1433 %     3       main.TestLoop::main @ 149 (245 bytes)
  75033 1434       4       util.RealtimeNanoClock::nanoTime (8 bytes)
  75034 1431       3       util.RealtimeNanoClock::nanoTime (8 bytes)   made not entrant
  75039 1435 %     4       main.TestLoop::main @ 149 (245 bytes)
  75043 1433 %     3       main.TestLoop::main @ 149 (245 bytes)   made not entrant

是的,两者都在JVM启动后75秒重新编译。要找出原因,请添加 。TestLoop.mainRealtimeNanoClock.nanoTime-XX:+UnlockDiagnosticVMOptions -XX:+LogCompilation

这将生成一个大型编译日志,我们将在其中查找在第 75 秒发生的事件。

<uncommon_trap thread='173414' reason='unstable_if' action='reinterpret' debug_id='0' compile_id='1232' compile_kind='osr' compiler='c2' level='4' stamp='75.676'>
<jvms bci='161' method='main.TestLoop main ([Ljava/lang/String;)V' bytes='245' count='1' backedge_count='533402' iicount='1'/>

由于字节码索引161,这是一个不常见的陷阱。换句话说,在JIT编译时,HotSpot没有为分支生成代码,因为它以前从未被执行过(这种推测性的死代码消除)。但是,为了保持编译代码的正确性,HotSpot 会放置一个陷阱来取消优化,并在推理条件失败时回退到解释器。这正是当条件变为 .unstable_ifmainelseiffalse

  1. Runtime1::counter_overflow().这再次与重新编译有关。运行 C1 编译的代码一段时间后,HotSpot 发现代码很热,并决定使用 C2 重新编译它。

    在本例中,我在编译器队列上捕获了争用锁。

结论

HotSpot JIT 编译器严重依赖推测优化。当推测条件失败时,这会导致去优化。对于低延迟应用程序来说,去优化确实非常糟糕:除了在解释器中切换到慢速执行之外,由于在 JVM 运行时中获取锁或将 JVM 带到安全点,这可能会间接导致意外的暂停。

取消优化的常见原因是 和 。如果要避免在延迟关键路径上取消优化,请确保“预热”虚拟方法的所有代码路径和所有可能的接收器。unstable_ifclass_check


答案 2

推荐