Java性能调优04——Java性能调优工具箱(中):Java监控和性能分析工具

本系列均取自《Java性能权威指南》这里只是一个个人备忘笔录

Java监控工具

要想深入了解 JVM 自身,需要使用 Java 的监控工具。JDK 自带以下所列工具。

jcmd
用来打印 Java 进程所涉及的基本类、线程和 VM 信息。它适用于脚本,可以像这 样执行:

% jcmd process_id command optional_arguments

jcmd help 可以列出所有的命令。
jcmd help <command> 可以给出特定命令的语法。


jconsole
提供 JVM 活动的图形化视图,包括线程的使用、类的使用和 GC 活动。


jhat
读取内存堆转储,并有助于分析。这是事后使用的工具。


jmap
提供堆转储和其他 JVM 内存使用的信息。可以适用于脚本,但堆转储必须在事后分析工具中使用。


jinfo
查看 JVM 的系统属性,可以动态设置一些系统属性。可适用于脚本。


jstack
转储 Java 进程的栈信息。可适用于脚本。


jstat
提供 GC 和类装载活动的信息。可适用于脚本。


jvisualvm
监视 JVM 的 GUI 工具,可用来剖析运行的应用,分析 JVM 堆转储(事后活动,虽然 jvisualvm 也可以实时抓取程序的堆转储)。


这些工具可广泛用于以下领域:

  1. 基本的 VM 信息
  2. 线程信息
  3. 类信息
  4. 实时 GC 分析
  5. 堆转储的事后处理
  6. JVM 的性能分析

你可能注意到了,工具和适用领域并非一一对应的,许多工具可用于多个领域。所以我们不是单个研究每个工具,而是着眼于 Java 重要的可观测领域,讨论这些工具如何提供这类信息。同时,我们还会讨论其他工具(有些是开源,有些是商业),虽然提供的基本功能相同,但是相比基本的 JDK 工具具有一定的优势。

 基本的VM信息

JVM 工具可以提供 JVM 进程的基本运行信息:它运行多久了,使用哪些 JVM 标志,以及 JVM 的系统属性,等等。

运行时间

此命令可以查看 JVM 运行的时长:

% jcmd process_id VM.uptime

系统属性

以下命令可以显示 System.getProperties() 的各个条目。

% jcmd process_id VM.system_properties

% jinfo -sysprops process_id

这包括通过命令行 -D 标志设置的所有属性,应用动态添加的所有属性和 JVM 的默认属性。

JVM版本

% jcmd process_id VM.version

JVM 命令行

jconsole 的“VM 摘要”页可以显示程序所用的命令行,或者用 jcmd 显示:

% jcmd process_id VM.command_line

JVM 调优标志

可用以下方式获得对应用生效的 JVM 调优标志:

% jcmd process_id VM.flags [-all]

调优标志

JVM 可以设置许多调优标志(JVM参数)。追踪这些标志及其默认值有点让人崩溃。上面最后两个 jcmd 示例对于获取这类信息很有用。command_line 显示直接在命令行指定的标志。flags 显示命令行设置的标志,以及 JVM 直接设置的标志(因为它们的值是通过自动优化决定的)。该命令加上 all 时,可以列出 JVM 内部所有的标志。

有几百个 JVM 调优标志,大多数都很令人费解,而且我们建议永远都不要对其作更改(参见下文的“信息太多?”)。诊断性能问题时,找出哪些标志起作用是很常见的事。JVM 运行时,可以用 jcmd 做到这一点。如果想找出特定 JVM 的平台特定的默认值是什么,那么在命令行上添加 -XX:+Printflagsfinal 会很有用。

想知道特定平台所设置的标志是什么,可以执行以下命令:

% java other_options -XX:+PrintFlagsFinal -version
……几百行输出,包括……
uintx InitialHeapSize                          := 4169431040    {product}
intx InlineSmallCode                           = 2000           {pd product}

你应该在命令行包括所有标志,因为有些标志会影响其他标志,特别是 GC 相关的标志。这个命令会打印 JVM 标志及其取值的完整列表(结果和 jcmd 结合 VM.flags -all 打印的相同)。

这些命令的标志数据以上述两种方式之一显示。输出第 1 行中的冒号表示标志使用的是非默认值。发生这种情况,可能是以下原因导致:

  1. 标志值直接在命令行指定。

  2. 其他标志间接改变了该标志的值。

  3. JVM 自动优化计算出来的默认值。

第 2 行(直接等于,没有冒号)表示,值是这个 JVM 版本的默认值。某些标志的默认值在不同平台上可能会不相同,输出的最右列会指示。product 表示在所有平台上的默认设置都是一致的。pd product 表示标志的默认值是独立于平台的。

信息太多

PrintFlagsFinal 会打出好几百个 JVM 可用的调优参数。

绝大多数标志的存在都是为了支持工程师收集更多与应用运行(以及错误行为)相关的信息。有个比较吸引人的标志称为 AllocatePrefetchLines(默认值为 3),它使得标志值可以改变,从而使预读指令在特定处理器上可以工作得更好。但这种随意的调优并没有必要。除非你有很充分的理由,否则不要更改标志值。就 AllocatePrefetchLines 标志来说,需要掌握应用预读性能、运行应用的 CPU 的特性以及更改这个数字对 JVM 自身的代码有什么影响。

最后一列可能的值还有 manageable(运行时可以动态更改标志的值)和 C2 diagnostic(为编译器工程师提供诊断输出,帮助理解编译器正以什么方式运作)。

还有另一种查看运行中的应用的此类信息的工具,叫作 jinfo。jinfo 的好处在于,它允许程序在执行时更改某个标志的值。

以下是如何获取进程中所有标志的值:

% jinfo -flags process_id

jinfo 带有 -flags 时可以提供所有标志的信息,否则只打印命令行所指定的标志。这两种数据都不像 -XX:+Printflagsfinal 那样易读,但 jinfo 有其他值得注意的特性。

jinfo 可以检查单个标志的值:

% jinfo -flag PrintGCDetails process_id
-XX:+PrintGCDetails

虽然 jinfo 本身不会显示是否 manageable,但 manageable(如 Printflagsfinal 输出中所标识的)的标志可以通过 jinfo 开启或关闭:

% jinfo -flag -PrintGCDetails process_id # turns off PrintGCDetails
% jinfo -flag PrintGCDetails process_id
-XX:-PrintGCDetails

需要当心的是,jinfo 可以更改任意标志的值,但并不意味着 JVM 会响应更改。比如说,大多数影响 GC 算法行为的标志都在启动时使用,以决定垃圾收集器的行为方式。之后通过 jinfo 更改标志值,并不会导致 JVM 改变它的行为。它会以初始时的算法继续执行。所以这个技术只会对那些在 Printflagsfinal 输出中标记为 manageable 的标志有效。

VM信息小结

  1. jcmd 可用来查找运行中的应用所在 JVM 的基本信息——包括所有调优标志的值。
  2. 命令行上添加 -XX:+Printflagsfinal 可输出标志的默认值。这在查看特定平台自动优化所判定的默认值时很有用。
  3. jinfo 在检查(某些情况下可以更改)单个标志时很有用。

线程信息

jconsole 和 jvisualvm 可以实时显示应用中运行的线程的数量。

查看运行线程的栈信息,对于判断线程是否被阻塞很有用。可以通过 jstack 获取栈信息:

% jstack process_id
…… 显示了每个线程的栈的众多输出 ……

也可以通过 jcmd 获取栈信息:

% jcmd process_id Thread.print
…… 显示了每个线程的栈的众多输出 ……

监控线程栈的详情见后面章节。

类信息

jconsole 或 jstat 可以提供应用已使用类的个数。jstat 还能提供类编译相关的信息。

应用使用类的更多细节和监控类编译的细节见后面章节。

实时GC分析

几乎所有的监控工具都能报告一些 GC 活动的信息。jconsole 可以用实时图显示堆的使用情况。jcmd 可以执行 GC 操作。jmap 可以打印堆的概况、永久代信息或者创建堆转储。jstat 可以为垃圾收集器正在执行的操作生成许多视图。

详细的见后

事后堆转储

jvisualvm 的 GUI 界面可以捕获堆转储,也可以用命令行 jcmd 或 jmap 生成。堆转储是堆使用情况的快照,可以用不同的工具进行分析,包括 jvisualvm 和 jhat。传统上,第三方处理堆转储的工具都领先于 JDK,所以后面章节使用第三方工具——Eclipse Memory Analyzer Tool——为例,展示如何在事后处理堆转储

性能分析工具

性能分析器是性能分析师工具箱中最重要的工具。Java 有许多性能分析器,各有优缺点。

性能分析经常需要使用各种工具——特别是那些采样分析器。即便是相同的应用,不同的分析器也能发现其他分析器所发现不了的问题。

几乎所有的 Java 性能分析工具都是用 Java 写的,并以“关联”(attaching)应用的方式进行性能分析——意思是性能分析器开启与目标应用之间的 socket(或其他通信通道)。随后目标应用和性能分析工具交换应用的行为信息。

这意味着,就像调优任何其他 Java 应用一样,你必须注意性能分析工具自身性能的调优。尤其是如果应用很大,需要传递给分析工具的数据非常多,那么分析工具就必须得有足够大的堆内存来处理这些数据。性能分析工具采用并发 GC 算法运行,通常是个不错的主意。在性能分析过程中,不合时宜的 Full GC 停顿会导致性能分析工具缓冲区中的数据溢出。

采样分析器

性能分析有两种模式:数据采样或数据探查。数据采样是性能分析的基本模式,带来的开销最小,这点很重要。性能分析为人诟病的一点就是,对应用进行的测量会改变它的性能。(然而,你必须进行性能分析:还有什么方法能让你知道程序中的猫是否存活?)限制性使用性能分析可以使得测试结果更接近现实模型,即通常情况下应用的表现行为。

不幸的是,采样分析器可能会遇到各种错误。计时器定期触发采样分析器,然后采样分析器检查每个线程并判断正在执行的方法。

如图展示采样中最常见的错误。线程交替执行 methodA(见图中的阴影块)和 methodB(见图中的白色块)。如果计时器只在线程执行 methodB 时触发,采样分析器就会报告成,在所有这段时间内线程都在执行 methodB,而实际上更多时间在执行 methodA。

采样中的常见错误

常见的采样错误还不止这一个。减少这类错误的方法是,拉长分析的时间段,同时减少采样间隔。但是减少采样间隔和尽量减小性能分析影响应用的目的相违背,这里需要有平衡。不同的性能分析工具考虑的平衡点也不同,这就是为什么不同的性能分析工具所报告的数据有很大差别的原因。

如图展示 GlassFish 应用服务器启动一个域时所测量出的基本采样分析。

采样模式 GlassFish

图中显示,大块时间(19%)都用在了 defineClass1() 上,接着是 getPackageSourcesInternal() 等方法。程序的启动性能是受 JVM 定义类过程的控制的,这并不奇怪。为了加快代码运行速度,必须改进类加载的性能。

请仔细留意上面的最后一句话:必须改善类加载的性能,而不是改善 defineClass1() 的性能。 改善性能的通常设想是,应该先优化性能分析结果中排在最上面的方法。然而,这种做法常常受限。这个案例中的 defineClass1() 是 JDK 的一部分,而且是本地方法(native method),除非改写 JVM,否则不可能改善它的性能。而且,即便能改写 JVM 使得这个方法少花 60% 的时间,但换算成整体性能的改善,也不过 10%——这无异于杯水车薪。

而更常见的情况是,排在性能分析结果顶上的方法只占了整体时间的 2% 或 3%。即便将它所用的时间砍掉一半(通常极为困难),也只会使应用的性能提高 1%。只盯着性能分析结果中最上头的方法,通常并不会让性能提高很多。

相反,你应该在最顶上那些方法所指引的区域中搜寻可优化的地方。GlassFish 性能工程师不会试图让类定义更快,但通常他们会找出如何加速类加载——装载更少的类、并行加载类等。

采样分析器小结

  1. 采样分析器是最常用的分析器。

  2. 因为采样分析器的采样频率相对较低,所以引入的测量失真也较小。

  3. 不同的采样分析器各有千秋,针对不同应用各有所长。

探查分析器

探查分析器相比于采样分析器,侵入性更强,但它们可以给出关于程序内部所发生的更有价值的信息。如下图探查的是与上一节采样分析相同的 GlassFish 域,采用的也是同一个性能分析工具,但这次使用的是探查模式。

探查模式 GlassFish

我们立即就能从这份性能分析结果中看出些问题。首先,现在最“热”的方法成了 getPackageSourcesInternal(),因为占用时间达到了 13%(而不是前个例子中的 4%)。性能分析结果中还有其他几个占用很多时间的方法,也都排到了前头,而 defineClass1() 已经完全消失了。这次工具还报告了每个方法被调用的次数,并且基于这个次数计算出了每次调用的平均时间。

难道这个性能分析结果比采样的好?这取决于能否有办法知道在给定的情况下哪种分析结果更精确。探查分析结果中的调用次数毫无疑问是精确的,而其他信息在判断哪段代码实际花费了更多时间,哪些有更多的优化空间时通常很有帮助。在这个例子中,虽然 ImmutableMap.get() 消耗了 12% 的整体时间,但它被调用了约 470 万次。减少这个方法的总调用次数比加快它的运行速度可以更显著地提升性能。

不过话说回来,探查分析器会在类加载时更改类的字节码(即插入统计调用次数的代码等)。相比采样分析器,探查分析器更可能会将性能偏差引入应用。比如,JVM 会内联小方法(参见第 4 章)使得执行时不会产生方法调用。编译器的这种判断是基于代码的大小,所以有可能使得这段代码不再被内联,这取决于如何探查代码。这会导致探查分析器高估某些方法对整体性能的影响。方法内联只是一个例子,说明编译器会基于代码在内存中的布局而做出决策。一般来讲,加入(更改)的探查代码越多,运行的性能分析结果就越有可能发生变更。

为何 ImmutableMap.get() 只在这里出现,而没在前面的采样分析结果中出现,还有一个很重要的技术原因。Java的采样分析器只能在线程位于安全点时采集线程样本——基本上只有在 JVM 分配内存的时候。get() 方法可能永远都不会进入安全点,所以可能永远都不会被采样。

在这个例子中,探查分析器和采样分析器给出的结果都指向同样的代码区域:类装载和类解析。实际上,不同分析器的结果可能指向的是完全不同的代码区域。性能分析器可以用来很好地估计,但也仅仅是估计而已:某时某刻它们也会犯错。

探查器小结

  1. 探查分析器可以给出更多的应用信息,但相对采样分析器,它对应用的影响更大。

  2. 探查分析器应该仅在小代码区域——一些类和包——中设置使用,以限制对应用性能的影响。

阻塞方法和线程时间线

如图是用另一种探查分析工具(NetBeans 性能分析器)分析的 GlassFish 启动。可以看出,此时的执行时间主要被 park() 和 parkNanos() 占用了(相对于占用更少的 read() 方法)。

NetBeans 性能分析器 GlassFish

这些方法(以及类似的阻塞方法)并不消耗 CPU 时间,所以对应用的整体 CPU 使用率没有贡献。没有必要优化它们的执行。应用线程花费 623 秒不是在执行 parkNanos() 方法,而是等待别的事情发生(例如,等待其他线程调用 notify() 方法)。park() 和 read() 方法同样如此。

因为这个原因,大多数分析器不会报告被阻塞的方法,相应的线程也被显示为空闲(这个例子,NetBeans 被设置为显式包括这些方法和其他 Java 级别的方法)。在这个例子中,这是件好事:停止运行的是 Java 线程池中的线程,这些线程用来执行服务器所收到的 servlet(和其他)请求。启动时没有请求发生,所以这些线程被阻塞,等待任务执行。这是正常状态。

在其他情况下,你总是希望能看到那些阻塞调用所花费的时间。线程在 wait()——等待其他线程唤醒——中的用时决定了许多应用的整体执行时间。大多数基于 Java 的性能分析器可以通过设置过滤器和调整其他选项来显示或隐藏这些阻塞方法。

另一方面,审视线程的执行模式而不是分析器给阻塞方法所标记的用时,常常更有价值。如图是Oracle Solaris Studio 性能分析工具中所显示的线程。

Solaris Studio

每个横向区域都是一个线程(图中有两个线程:线程 1.3 和线程 1.2)。颜色(或不同的灰色)条表示不同方法的执行过程,空白区域表示线程没有在执行。从更高角度来观察,线程 1.2 先是执行了大量代码,然后等待线程 1.3,线程 1.3 之后稍稍等待线程 1.2 执行其他事情,等等。用工具进一步深入这些区域,可以让我们了解线程之间是如何相互影响的。

还可以注意到,有些空白区域没有任何线程在执行。这张图只显示了应用许多线程中的两个,所以这两个线程可能一起在等待其他线程,或者想成正在执行阻塞调用 read()(或类似的)。

阻塞方法和线程时间线小结

  1. 线程被阻塞可能是性能问题,也可能不是,有必要进一步调查它们为何被阻塞。

  2. 通过正被阻塞的方法调用,或者分析线程的时间线,可以辨认出被阻塞的线程。

本地分析器

本地性能分析工具是指分析 JVM 自身性能的工具。这类工具可以看到 JVM 内部的工作原理,如果应用自身含有本地库,这类工具也能看到本地库代码的内部。所有本地分析工具都可以用来分析 JVM 的 C 代码(以及任何本地库),而有些本地工具则可以用来分析任何 Java 和 C/C++ 应用。

下图有点眼熟,是 Oracle Solaris Studio 分析器分析 GlassFish 启动的结果。

Solaris Studio本地分析

它是本地分析器,可以接受 Java 和 C/C++ 代码。(虽然名字中有 Solaris,但它也可以在 Linux 系统上运行。实际上,这些图片都是 Linux OS 上截取的分析结果。不过,如果在 Solaris 的内核结构上运行,这个工具可以展示更多的应用信息。)

请注意,第一处与前面不同的是,记录下的应用总 CPU 时间为 25.1 秒,其中 20 秒是 JVM-System 所用。这是 JVM 自身代码的特性:JVM 编译器线程和 GC 线程(加上其他一些辅助线程)。我们可以进一步了解到,实际上,这个例子的所有时间都花费在了编译器上(启动过程确实如此,期间有许多代码需要编译)。这个例子中,GC 线程只花了很少量的时间。

除非是为了深入研究 JVM 自身,否则这些本地信息就足够了。如果我们愿意,可以进一步检查实际的 JVM 功能并优化它们。不过,这个工具所透露出来的关键信息是——基于 Java 的性能分析工具所不能提供的——应用花在 GC 上的时间。在基于 Java 的性能分析工具中,GC 线程的影响几乎看不到。(除非测试所运行的机器是 CPU 受限,否则编译器线程占用大量时间并无大碍:虽然编译线程会消耗大量的 CPU 时间,但只要机器上有更多可用的 CPU,应用自身就不受影响,因为编译是在后台发生。)

一旦检测出本地代码的影响,就可以过滤出来,以便重点考虑实际的启动过程。如:

采样分析器再次把 defineClass1() 指为了最热的方法,虽然这个方法及其子调用的实际用时——5.041 秒中的 0.67 秒——占了约 11%(不像前面采样分析器报告的那么显著)。分析结果还指出了其他一些需要调查的信息:读取和解压 JAR 文件。由于和类装载有关,这说明我们追踪的方向是正确——但在这个例子中,重要的是看到了实际读取(通过 inflateBytes() 方法)JAR 文件 I/O 只占了极少的百分点。其他工具则不会告诉我们这些信息——部分是因为 Java ZIP 库中的本地代码被当作阻塞调用而被过滤掉了。

无论你用上述哪种性能分析工具,或更好的工具,至关重要的一点就是熟悉它们的特性。性能分析器是查找性能瓶颈最重要的工具,但你必须学会如何使用它们,然后找到需要优化的代码区域,而不是仅仅关注最上头的方法

本地分析器小结

  1. 本地性能分析器可以提供 JVM 和应用代码内部的信息。

  2. 如果本地性能分析器显示 GC 占用了主要的 CPU 使用时间,优化垃圾收集器就是正确的做法。然而,如果显示编译线程占用了明显的时间,则说明通常对应用性能没什么影响。

更新时间:2020-03-07 09:59:06

本文由 寻非 创作,如果您觉得本文不错,请随意赞赏
采用 知识共享署名4.0 国际许可协议进行许可
本站文章除注明转载/出处外,均为本站原创或翻译,转载前请务必署名
原文链接:https://www.zhouning.group/archives/java性能调优04java性能调优工具箱中java监控工具
最后更新:2020-03-07 09:59:06

评论

Your browser is out of date!

Update your browser to view this website correctly. Update my browser now

×