输出JDK12中无vmop操作的Safepoint + stats日志 [英] Safepoint+stats log with None vmop operation in output JDK12

问题描述

我正在使用 -Xlog:safepoint + stats = debug:file = safepoint.log vm参数在JDK12上运行应用程序，以记录安全点操作并与ZGC一起运行.我有问题要了解日志输出:

I am running application on the JDK12 with the -Xlog:safepoint+stats=debug:file=safepoint.log vm parameter to log the safepoint actions and running with ZGC. I have the problem to understand the log output:

[1408.417s][debug][safepoint,stats]           vmop                            [ threads:    total initially_running wait_to_block ][ time:    spin   block    sync cleanup    vmop ] page_trap_count
[1412.164s][debug][safepoint,stats] 1412.162: ZOperation                    [               376                 0             7 ][             0       0       0       0       1 ]               7
[1413.164s][debug][safepoint,stats] 1413.164: None                          [               376                 0             0 ][             0       0       0       0       0 ]               0
[1414.165s][debug][safepoint,stats] 1414.164: None                          [               376                 0             1 ][             0       0       0       0       0 ]               1

我知道第一行告诉我们ZOperation用了1毫秒，并且有7个线程参与了阻塞.

I understand the first line that tells that ZOperation took 1 millis, and 7 threads contributed in blocking.

我不明白第二行，什么是无" vmop操作?看起来该操作的持续时间为0.实际上是0还是0，因为它花费了不到1毫秒的时间?如果是，则可以设置更高的时间记录粒度，以查看花费了多少纳秒?或微秒?

I don't understand the second line, what is the "None" vmop operation? It looks like the duration of that operation is 0. It is really 0 or it is 0 because it took less than 1 millisecond? If yes it is possible to set higher granularity of time logging, to see how many nanoseconds it took ? or microseconds?

我每秒都记录了许多此无"操作.我想知道在此暂停期间JVM在做什么.我每10秒跟踪一次ZGC时间和SafePoint时间，并且汇总的安全点时间比汇总的gc暂停时间高5倍.我想以某种方式减少我的应用程序的安全点时间.

I have many of this "None" operation logged per seconds. I would like to know what the JVM is doing during that pause. I track the ZGC time and SafePoint time every 10 seconds, and the aggregated safepoint time is 5 times higher than aggregated gc pause time. I would like to somehow decrease that safepoint time for my application.

推荐答案

这是没有VM操作的安全点.它的目的是执行定期清理任务，例如缩小空闲监视器或清除内联高速缓存缓冲区，只有在没有Java线程运行时，才能安全地完成这些工作.

This is a safepoint with no VM operation. Its purpose is to perform periodic cleanup tasks like deflating idle monitors or purging inline cache buffer, which can be safely done only when no Java threads are running.

如果要执行清理任务，则每GuaranteedSafepointInterval毫秒会强制执行一次安全点检查.默认值为1000.请注意，在这种情况下，无操作安全点恰好在上一个安全点之后1秒发生.

If there are cleanup tasks to do, a mandatory safepoint happens every GuaranteedSafepointInterval milliseconds. The default value is 1000. Note that in your case no-op safepoint happens exactly 1 second after the previous safepoint.

间隔可以通过

-XX:+UnlockDiagnosticVMOptions -XX:GuaranteedSafepointInterval=<ms>

为避免混淆，在JDK 13中，此类无操作安全点获得了Cleanup操作名称.

To avoid confusion, in JDK 13 such no-op safepoints got Cleanup operation name.

这篇关于输出JDK12中无vmop操作的Safepoint + stats日志的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！