如何测量 JVM 启动时间？答案

【问题标题】：How do I measure JVM startup time?如何测量 JVM 启动时间？
【发布时间】：2016-09-04 20:45:38
【问题描述】：

我有一个用 java 编写的应用程序，我想知道到达 static void int main(String args) 需要多长时间，以及它在那个阶段正在做什么，我该如何实现？

我知道微软有一个名为 MPGO（管理器配置文件引导优化）的工具，Java 有没有类似的工具？

【问题讨论】：

标签： java jvm

【解决方案1】：

一种从 Java 应用程序内部测量启动时间的简单方法：

import java.lang.management.ManagementFactory;

public class Test {

    public static void main(String[] args) {
        long currentTime = System.currentTimeMillis();
        long vmStartTime = ManagementFactory.getRuntimeMXBean().getStartTime();
        System.out.println(currentTime - vmStartTime);
    }
}

您可以使用 JVMTI agent 来跟踪 VM 事件，例如类加载、垃圾收集、方法编译等。这是我制作的一个简单代理 - vmtrace（以及用于 Windows 的 compiled dll）。

运行java -agentpath:path\to\vmtrace.dll Main，事件跟踪将打印到stderr：

[0.00000] VMTrace started
[0.00182] Dynamic code generated: flush_icache_stub
[0.00187] Dynamic code generated: get_cpu_info_stub
[0.00519] Dynamic code generated: getCPUIDNameInfo_stub
[0.00524] Dynamic code generated: forward exception
[0.00526] Dynamic code generated: call_stub
...
[0.01182] Loading class: java/lang/Object
[0.01198] Loading class: java/lang/String
[0.01206] Loading class: java/io/Serializable
...
[0.05620] VM initialized
[0.05664] Class prepared: java/lang/invoke/MethodHandle
[0.05672] Loading class: java/lang/invoke/MethodHandleImpl
[0.05732] Class prepared: java/lang/invoke/MethodHandleImpl
[0.05738] Loading class: java/lang/invoke/MethodHandleImpl$1
[0.05743] Class prepared: java/lang/invoke/MethodHandleImpl$1
[0.05755] Loading class: java/lang/invoke/MethodHandleImpl$2
[0.05759] Loading class: java/util/function/Function
[0.05768] Class prepared: java/util/function/Function
...

【讨论】：

我已经尝试过了，它似乎给了我一些不错的价值，但有时描述丢失或格式错误，即我得到 [0.02056] Dber 和 [0.031ber 之类的东西。另一件奇怪的事情是我收到两条 VM 启动消息。也不是所有的时间戳都是连续的，是不是因为线程？最后，没有名为 [VMTrace end] 的最后一条记录可以让我计算最后两条记录之间的时间间隔。
@Har 是的，在多线程环境中，由于并发问题，输出可能会出现混杂。围绕trace 函数的互斥锁应该可以解决问题。最好将代理输出与应用程序输出分开 - 您可以将文件名指定为代理参数。
@Har 我已更新 vmtrace 以同步输出并记录 [VM 已损坏]。

【解决方案2】：

使用java 9，您可以添加-Xlog:class+init=info:file=trace.log 来跟踪类初始化（这是类加载后的下一步），然后过滤您的主类。这是一个新的logging feature。

您也可以让它记录所有内容以查看启动前发生的情况，但记录的事件数量可能会扭曲结果。

在 java 8 和更低版本中，不同的 VM 组件有自己的日志记录（通常只是通过 printf），并且类加载是不包括时间戳的。

【讨论】：

如何指定启用时间戳？到目前为止，我找不到该选项我有 -XX:+TraceClassResolution -XX:+TraceClassLoading -XX:+UnlockDiagnosticVMOptions -XX:LogFile=C:\Users\Har\out.txt -XX:+PrintCompilation
抱歉，我记错了，在 8 中，您只能获得 printcompilation 和 gc 日志的时间戳（两者都对确定启动时间没有用处），而不是类加载。我猜这些不一致是他们统一登录 9 的原因之一

【解决方案3】：

另一种测量启动时间的方法是使用ProcessHandle 从Java 9 开始可用：

public static void main(String[] args) {
    var currentTimeMillis = System.currentTimeMillis();
    var processStartTime = ProcessHandle.current().info().startInstant().get();
    System.out.println(currentTimeMillis - processStartTime.toEpochMilli());
}

【讨论】：

【解决方案4】：

如果您使用 jrockit jvm，您可以添加以下标志来了解 jvm 启动的时间

-Xverbose:codegen

2016 年 5 月 9 日更新

下面继续我们的对话。 jstat 将提供有关类加载器的基于时间的统计信息。必须通过执行获得一个虚拟机id（vmid）

jps

有了这个id可以执行以下操作

jstat -class {vmid} 1000 10

这将在 10 秒内每秒提供一次类加载器的快照。

【讨论】：

这些选项在免费的 java 8 se 版本中可用吗？
最好的功能被合并到热点中。在下一页的调试标题下查看 Java 8 se 的此信息。 oracle.com/technetwork/articles/java/vmoptions-jsp-140102.html
看看 ciTime 或者 traceClassLoading
哇，非常感谢，这就是我要找的东西，我试试看
啊，它没有给我时间，它只说明了它的加载内容，但没有说明加载每个模块需要多长时间，我得到类似：[Loaded java.text.DecimalFormat from C:\Program文件\Java\jdk1.8.0_45\jre\lib\rt.jar]