GC调整:工具
在优化JVM以实现更高效的垃圾收集之前,您需要获取有关其当前行为的信息,以了解GC对您的应用程序的影响以及最终用户的感知。有多种方法可以观察GC的工作,在本章中我们将介绍几种不同的可能性。
在观察GC行为时,JVM运行时提供了原始数据。此外,还有可以根据原始数据计算的派生度量。例如,原始数据包含:
- 目前占用的内存池,
- 内存池的容量,
- 个别GC暂停的持续时间,
- 这些暂停的不同阶段的持续时间。
派生的度量包括例如应用程序的分配和提升率。本章将主要讨论获取原始数据的方法。最重要的派生度量将在下一章中讨论,讨论最常见的GC相关性能问题。
JMX API
从正在运行的JVM获取GC相关信息的最基本方法是通过标准JMX API。这是JVM公开有关JVM运行时状态的内部信息的标准方法。您可以通过在同一JVM内运行的应用程序或使用JMX客户端以编程方式访问此API。
两个最流行的JMX客户端是JConsole和JVisualVM(安装了相应的插件)。这两个工具都是标准JDK发行版的一部分,因此入门很容易。如果您在JDK 7u40或更高版本上运行,则还可以使用捆绑到JDK中的第三个工具Java Mission Control。
所有JMX客户端都作为连接到目标JVM的单独应用程序运行。如果在同一台机器上运行,则目标JVM可以是客户端的本地JVM,也可以是远程JVM。对于来自客户端的远程连接,JVM必须明确允许远程JMX连接。这可以通过将特定系统属性设置为您希望启用JMX RMI连接的端口来实现:
java -Dcom.sun.management.jmxremote.port = 5432 com.yourcompanyYourApp
在上面的示例中,JVM为JMX连接打开端口5432。
将JMX客户端连接到感兴趣的JVM并导航到MBean列表后,在节点“ java.lang / GarbageCollector ” 下选择MBean 。请参阅下面的两个屏幕截图,分别展示来自JVisualVM和Java Mission Control的GC行为信息:
如上面的屏幕截图所示,存在两个垃圾收集器。其中一个收藏家负责清洁年轻一代和一个老一代。这些元素的名称对应于所使用的垃圾收集器的名称。在上面的屏幕截图中,我们可以看到特定的JVM正在为年轻一代运行ParallelNew,并为旧一代运行Concurrent Mark和Sweep。
对于每个收集器,JMX API公开以下信息:
- CollectionCount - 此收集器在此JVM中运行的总次数,
- CollectionTime - 收集器运行时间的累计持续时间。时间是所有GC事件的挂钟时间的总和,
- LastGcInfo - 有关上次垃圾收集事件的详细信息。此信息包含该事件的持续时间,事件的开始和结束时间以及在上一次收集之前和之后使用不同的内存池,
- MemoryPoolNames - 此收集器管理的内存池的名称,
- 名称 - 垃圾收集器的名称
- ObjectName - 此MBean的名称,由JMX规范指定,
- 有效 - 显示此收集器在此JVM中是否有效。我个人在这里从来没有见过任何“真实”的东西
根据我的经验,这些信息不足以对垃圾收集器的效率做出任何结论。它可以用于任何用途的唯一情况是当您愿意构建自定义软件以获取有关垃圾收集事件的JMX通知时。这种方法很少被使用,我们将在下一节中看到,它们提供了更好的方法来获得对垃圾收集活动的有益见解。
JVisualVM
JVisualVM通过名为“ VisualGC ” 的单独插件向基本JMX客户端功能添加额外信息。它提供了GC事件的实时视图以及JVM内不同内存区域的占用情况。
Visual GC插件最常见的用例是监视本地运行的应用程序,当应用程序开发人员或性能专家想要一种简单的方法来获取有关应用程序测试运行期间GC的一般行为的可视信息时。
在图表的左侧,您可以看到不同内存池的当前用法的实时视图:元空间或永久生成,旧生成,伊甸园生成和两个幸存者空间。
在右侧,前两个图表与GC无关,暴露了JIT编译时间和类加载时序。以下六个图表显示了内存池使用情况的历史记录,每个池的GC集合数以及该池的GC累计时间。此外,每个池还显示其当前大小,峰值使用量和最大大小。
以下是目前居住在Young一代中的对象年龄的分布。对物体持久监测的全面讨论超出了本章的范围。
与纯JMX工具相比,JVisualVM的VisualGC插件确实提供了更好的JVM洞察力,因此当您的工具包中只有这两个工具时,请选择VisualGC插件。如果您可以使用本章中提到的任何其他解决方案,请继续阅读。替代选项可以为您提供更多信息和更好的洞察力。然而,在“Profilers”部分中讨论了JVisualVM适用的特定用例 - 即分配分析,因此我们决不会降低该工具的一般性,仅针对特定用例。
jstat
下一个要查看的工具也是标准JDK发行版的一部分。该工具称为“ jstat ” - 一种Java虚拟机统计监视工具。这是一个命令行工具,可用于从正在运行的JVM获取指标。连接的JVM可以再次是本地的或远程的。可以通过从命令行运行“ jstat -option ” 来获取jstat能够公开的度量标准的完整列表。最常用的选项是:
+ ----------------- + ------------------------------- -------------------------------- +
| 选项| 显示... |
+ ----------------- + ------------------------------- -------------------------------- +
| class | 关于类加载器行为的统计信息|
|编译器| HotSpot Just-In-Time com-的行为统计
| | piler |
| gc | 垃圾收集堆行为的统计信息|
| gccapacity | 世代及其能力的统计数据
| | 相应的空间。|
| gccause | 垃圾收集统计信息摘要(与-gcutil相同),|
| | 与最后和当前的原因(如果适用)|
| | 垃圾收集事件。|
| gcnew | 统计新一代的行为。|
| gcnewcapacity | 新一代大小的统计数据及其相关性
| | 自由空间。|
| gcold | 统计旧的和永久的行为 - |
| | 蒸发散。|
| gcoldcapacity | 统计老一代的规模。|
| gcpermcapacity | 永久代的规模统计。|
| gcutil | 垃圾收集统计摘要。|
| printcompilation | 垃圾收集统计摘要。|
+ ----------------- + ------------------------------- -------------------------------- +
此工具对于快速了解JVM运行状况以查看垃圾收集器是否按预期运行非常有用。例如,您可以通过“ jstat -gc -t PID 1s” 运行它,其中PID是您要监视的JVM的进程ID。您可以通过运行“jps”获取PID以获取正在运行的Java进程的列表。因此,每个第二个jstat将在标准输出中打印一个新行,类似于以下示例:
时间戳S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
200.0 8448.0 8448.0 8448.0 0.0 67712.0 67712.0 169344.0 169344.0 21248.0 20534.3 3072.0 2807.7 34 0.720 658 133.684 134.404
201.0 8448.0 8448.0 8448.0 0.0 67712.0 67712.0 169344.0 169343.2 21248.0 20534.3 3072.0 2807.7 34 0.720 662 134.712 135.432
202.0 8448.0 8448.0 8102.5 0.0 67712.0 67598.5 169344.0 169343.6 21248.0 20534.3 3072.0 2807.7 34 0.720 667 135.840 136.559
203.0 8448.0 8448.0 8126.3 0.0 67712.0 67702.2 169344.0 169343.6 21248.0 20547.2 3072.0 2807.7 34 0.720 669 136.178 136.898
204.0 8448.0 8448.0 8126.3 0.0 67712.0 67702.2 169344.0 169343.6 21248.0 20547.2 3072.0 2807.7 34 0.720 669 136.178 136.898
205.0 8448.0 8448.0 8134.6 0.0 67712.0 67712.0 169344.0 169343.5 21248.0 20547.2 3072.0 2807.7 34 0.720 671 136.234 136.954
206.0 8448.0 8448.0 8134.6 0.0 67712.0 67712.0 169344.0 169343.5 21248.0 20547.2 3072.0 2807.7 34 0.720 671 136.234 136.954
207.0 8448.0 8448.0 8154.8 0.0 67712.0 67712.0 169344.0 169343.5 21248.0 20547.2 3072.0 2807.7 34 0.720 673 136.289 137.009
208.0 8448.0 8448.0 8154.8 0.0 67712.0 67712.0 169344.0 169343.5 21248.0 20547.2 3072.0 2807.7 34 0.720 673 136.289 137.009
让我们使用jstat联机帮助页中输出属性的解释来解释上面的输出。利用获得的知识,我们可以看到:
- jstat从此JVM启动200秒后连接到JVM。该信息出现在标有“ 时间戳 ” 的第一列中。从同一列中可以看出,jstat每秒从JVM收集一次信息,如命令中给出的“1s”参数中所指定的那样。
- 从第一行开始,我们可以看到,到目前为止,年轻一代已被清洗34次,整个堆已经清理了658次,分别由“YGC ”和“ FGC ”列表示。
- 如“ YGCT ”栏中所示,年轻一代垃圾收集器已经运行了0.720秒。
- 如“ FGCT ”列中所示,完整GC的总持续时间为133.684秒。这应该立即引起我们的注意 - 我们可以看到,在JVM运行的总共200秒中,66%的时间花费在完整的GC循环中。
当我们查看下一行时,问题变得更加清晰,一秒钟之后收集信息。
- 现在我们可以看到,在“ FGC ”列中指示的最后一次jstat打印出数据之间,在一秒钟内运行了四个Full GCs 。
- 这四个GC暂停几乎整个过程 - 正如“ FGCT ”栏中的差异所示。相比于第一排,全GC已经运行了928毫秒,或总时间的92.8%。
- 同时,如“ OC ”和“ OU ”列所示,我们可以看到几乎所有旧代容量为169,344.0 KB(“ OC ”),经过四次采集周期的所有清洁工作要完成,169,344.2 KB(“ OU ”)仍在使用中。在928 ms内清理800字节不应被视为正常行为。
只有jstat输出中的这两行才能让我们了解应用程序出现严重错误。将相同的分析应用于下一行,我们可以确认问题仍然存在并且变得更糟。
JVM几乎停滞不前,GC耗尽了90%以上的可用计算能力。由于所有这些清洁工作,几乎所有老一代仍然在使用,进一步证实了我们的疑虑。事实上,这个例子在一分钟后死于“ java.lang.OutOfMemoryError:GC开销超出限制 ”错误,消除了最后遗留的疑问,不管事情是否真的很糟糕。
从示例中可以看出,jstat输出可以在行为不端的垃圾收集器方面快速揭示有关JVM运行状况的症状。作为一般准则,只需查看jstat输出即可快速显示以下症状:
- 当与“ 时间戳 ”列中的JVM的总运行时间进行比较时,最后一列“ GCT ” 中的更改提供有关垃圾收集开销的信息。如果您每隔一秒看到一次,那么与总运行时间相比,该列中的值会显着增加,从而会产生很高的开销。可以容忍多少GC开销是特定于应用程序的,并且应该从您手头的性能要求中得出,但作为基本规则,超过10%的任何内容看起来都是可疑的。
- 跟踪年轻和完整GC计数的“ YGC ”和“ FGC ”列的快速变化也倾向于暴露问题。通过为应用程序线程添加许多停止世界的暂停,再次堆积再次影响吞吐量时,GC过于频繁地暂停。
- 当您看到“ OU ”列中的旧代用法几乎等于“ OC ”列中旧代的最大容量时,在“ FGC ”列数增加之后没有减少,则表示旧代集合已经发生,你已经暴露了另一个表现不佳的GC症状。
GC日志
GC相关信息的下一个来源可通过垃圾收集器日志访问。由于它们是在JVM中构建的,因此GC日志为您(可以说)提供了有关垃圾收集器活动的最有用和最全面的概述。GC日志是事实上的标准,应该作为垃圾收集器评估和优化的最终真实来源。
垃圾收集器日志采用纯文本格式,可以由JVM打印到标准输出或重定向到文件。有许多与GC日志记录相关的JVM选项。例如,您可以记录每个GC事件之前和期间停止应用程序的总时间(-XX:+ PrintGCApplicationStoppedTime)或公开有关正在收集的不同引用类型的信息(-XX:+ PrintReferenceGC)。
可以通过在启动脚本中指定以下内容来实现每个JVM应记录的最小值:
-XX:+ PrintGCTimeStamps -XX:+ PrintGCDateStamps -XX:+ PrintGCDetails -Xloggc:<filename>
这将指示JVM将每个GC事件打印到日志文件,并将每个事件的时间戳添加到日志中。根据所使用的GC算法,暴露给日志的确切信息会有所不同。使用ParallelGC时,输出应类似于以下内容:
199.879:[完整GC(人类工效学)[PSYoungGen:64000K-> 63998K(74240K)] [ParOldGen:169318K-> 169318K(169472K)] 233318K-> 233317K(243712K),[Metaspace:20427K-> 20427K(1067008K)], 0.1473386秒] [时间:用户= 0.43 sys = 0.01,实际= 0.15秒]
200.027:[全GC(人机工程学)[PSYoungGen:64000K-> 63998K(74240K)] [ParOldGen:169318K-> 169318K(169472K)] 233318K-> 233317K(243712K),[Metaspace:20427K-> 20427K(1067008K)], 0.1567794秒] [时间:用户= 0.41 sys = 0.00,实际= 0.16秒]
200.184:[全GC(人体工程学)[PSYoungGen:64000K-> 63998K(74240K)] [ParOldGen:169318K-> 169318K(169472K)] 233318K-> 233317K(243712K),[Metaspace:20427K-> 20427K(1067008K)], 0.1621946秒] [时间:用户= 0.43 sys = 0.00,实际= 0.16秒]
200.346:[全GC(人机工程学)[PSYoungGen:64000K-> 63998K(74240K)] [ParOldGen:169318K-> 169318K(169472K)] 233318K-> 233317K(243712K),[Metaspace:20427K-> 20427K(1067008K)], 0.1547695秒] [时间:用户= 0.41 sys = 0.00,实际= 0.15秒]
200.502:[全GC(人机工程学)[PSYoungGen:64000K-> 63999K(74240K)] [ParOldGen:169318K-> 169318K(169472K)] 233318K-> 233317K(243712K),[Metaspace:20427K-> 20427K(1067008K)], 0.1563071秒] [时间:用户= 0.42 sys = 0.01,实际= 0.16秒]
200.659:[全GC(人机工程学)[PSYoungGen:64000K-> 63999K(74240K)] [ParOldGen:169318K-> 169318K(169472K)] 233318K-> 233317K(243712K),[Metaspace:20427K-> 20427K(1067008K)], 0.1538778秒] [时间:用户= 0.42 sys = 0.00,实际= 0.16秒]
这些不同的格式将在“ GC算法:实现 ” 一章中详细讨论,因此如果您不熟悉输出,请首先阅读本章。如果您已经可以解释上面的输出,那么您可以扣除:
- 在JVM启动后大约200秒提取日志。
- 在日志中存在的780毫秒期间,JVM暂停了五次GC(我们排除了第 6 次暂停,因为它开始时没有在时间戳上结束)。所有这些暂停都是完整的GC暂停。
- 这些暂停的总持续时间为777毫秒,占总运行时间的99.6%。
- 同时,从老一代的容量和消耗来看,在GC反复尝试释放一些内存之后,几乎所有旧代容量(169,472 kB)仍在使用(169,318 K)。
从输出中,我们可以确认应用程序在GC方面表现不佳。JVM几乎停滞不前,GC耗尽了超过99%的可用计算能力。由于所有这些清洁工作,几乎所有老一代仍然在使用,进一步证实了我们的怀疑。示例应用程序与前一个jstat部分中使用的相同,仅在几分钟后死于“ java.lang.OutOfMemoryError:GC开销限制超出 ”错误,确认问题严重。
从示例中可以看出,GC日志是有价值的输入,可以根据行为不当的垃圾收集器来揭示有关JVM运行状况的症状。作为一般指导原则,只需查看GC日志即可快速显示以下症状:
- GC开销太多。当GC暂停的总时间太长时,应用程序的吞吐量会受到影响。限制是特定于应用程序的,但作为一般规则,超过10%的限制已经看起来可疑。
- 个人停顿时间过长。每当个别暂停开始花费太长时间时,应用程序的延迟开始受到影响。例如,当延迟要求要求应用程序中的事务在1,000毫秒内完成时,您不能容忍任何超过1,000毫秒的GC暂停。
- 老一代消费在极限。即使在几个完整的GC循环之后,只要老一代仍然接近完全利用,您就会面临GC成为瓶颈的情况,这可能是由于资源不足或内存泄漏造成的。此症状总是会触发GC开销通过屋顶。
正如我们所看到的,GC日志可以为我们提供有关垃圾收集相关内容的详细信息。然而,对于除了最微不足道的应用之外的所有应用,这导致大量数据,这些数据往往难以被人阅读和解释。
GCViewer
处理GC日志中的信息泛滥的一种方法是为GC日志文件编写自定义解析器以可视化信息。在大多数情况下,由于产生信息的不同GC算法的复杂性,这将不是一个合理的决定。相反,一个好方法是从已经存在的解决方案开始:GCViewer。
GCViewer是一个用于解析和分析GC日志文件的开源工具。GitHub网页提供了所有呈现指标的完整描述。在下文中,我们将回顾使用此工具的最常用方法。
第一步是获取有用的垃圾收集日志文件。它们应反映您在此性能优化会话期间感兴趣的应用程序的使用情况。如果您的运营部门每周五下午都抱怨,应用程序会变慢,如果您想验证GC是否是罪魁祸首,那么从星期一早上分析GC日志是没有意义的。
收到日志后,您可以将其提供给GCViewer以查看类似于以下内容的结果:
图表区域专门用于GC事件的可视化表示。可用信息包括所有内存池和GC事件的大小。在上图中,只显示了两个指标:使用蓝线显示总使用的堆和使用下方黑条显示的单个GC暂停持续时间。
从这张图中我们可以看到的第一个有趣的事情是内存使用量的快速增长。在大约一分钟内,总堆消耗几乎达到可用的最大堆。这表明存在问题 - 几乎所有堆都被消耗,新的分配无法继续,从而触发频繁的完整GC循环。应用程序要么泄漏内存,要么设置为使用配置不足的堆大小运行。
图表中可见的下一个问题是GC暂停的频率和持续时间。我们可以看到,在最初的30秒后,GC几乎不断运行,最长的暂停时间超过1.4秒。
在右边有一个带有三个标签的小面板。在“摘要”选项卡下,最有趣的数字是“吞吐量”和“GC暂停次数”,以及“完整GC暂停次数”。吞吐量显示应用程序运行时用于运行应用程序的部分,而不是花费时间进行垃圾回收。
在我们的例子中,我们面临着6.28%的吞吐量。这意味着在GC上花费了93.72%的CPU时间。这是应用程序遭受痛苦的明显症状 - 它不是花费宝贵的CPU周期来实际工作,而是花费大部分时间试图摆脱垃圾。
下一个有趣的标签是“暂停”:
“暂停”选项卡显示GC暂停的总计,平均值,最小值和最大值,分别作为总计和次要/主要暂停。优化应用程序以实现低延迟,这可以让您第一眼看到您是否面临过长的暂停。同样,我们可以确认累计的634.59秒的暂停持续时间和3,938的GC暂停总数 太高,考虑到总运行时间超过11分钟。
有关GC事件的更多详细信息,请访问主要区域的“事件详细信息”选项卡:
在这里,您可以看到日志中记录的所有重要GC事件的摘要:次要和主要暂停和并发,而不是世界各地的GC事件。在我们的案例中,我们可以看到一个明显的“赢家”,即完整的GC事件对吞吐量和延迟的贡献最大,再次确认3,928个完整GC暂停需要634秒才能完成。
从示例中可以看出,GCViewer可以快速可视化症状,告诉我们JVM是否在行为不端的垃圾收集器方面是健康的。作为一般指导原则,可以快速揭示以下症状,可视化GC的行为:
- 吞吐量低。当应用程序的吞吐量降低并且落在可容忍的水平之下时,应用程序花费在做有用工作上的总时间会减少。什么是“可容忍的”取决于您的应用程序及其使用场景。一条经验法则表明,任何低于90%的值都应引起您的注意,并可能需要进行GC优化。
- 个别GC暂停时间过长。每当个别暂停开始花费太长时间时,应用程序的延迟开始受到影响。例如,当延迟要求要求应用程序中的事务在1,000毫秒内完成时,您不能容忍任何超过1,000毫秒的GC暂停。
- 高堆消耗。每当老一代即使在几个完整的GC周期后仍然接近完全利用时,您也面临着应用程序处于极限的情况,这可能是由于资源不足或内存泄漏造成的。此症状也会对吞吐量产生重大影响。
作为一般性评论 - 可视化GC日志绝对是我们推荐的。您无需直接使用冗长而复杂的GC日志,而是可以访问人类可理解的相同信息的可视化。
剖析
下一组要介绍的工具是剖析器。与前面部分介绍的工具相反,GC相关区域是分析器提供的功能的子集。在本节中,我们仅关注分析器的GC相关功能。
本章从警告开始 - 作为工具类别的剖析器往往被误解并用于有更好替代方案的情况。有时,分析器真正发挥作用,例如在应用程序代码中检测到CPU热点时。但对于其他几种情况,还有更好的选择。
这也适用于垃圾收集调整。在检测您是否遇到GC引起的延迟或吞吐量问题时,您实际上并不需要分析器。前面章节中提到的工具(jstat或原始/可视化GC日志)可以更快,更便宜地检测您是否有任何需要担心的问题。特别是在从生产部署收集数据时,由于引入的性能开销,分析器不应该是您的首选工具。
但是,只要您确认需要优化GC对应用程序的影响,分析器就可以通过公开有关对象创建的信息来发挥重要作用。如果退后一步 - GC暂停是由不适合特定内存池的对象触发的。这只能在您创建对象时发生。并且所有分析器都能够通过分配分析来跟踪对象分配,为您提供有关内存中实际驻留的内容以及分配跟踪的信息。
分配概要分析为您提供有关应用程序创建大多数对象的位置的信息。在产生最大数量的对象时,暴露顶级内存消耗对象和应用程序中的线程是使用分析器进行GC调整时应该获得的好处。
在以下部分中,我们将看到三种不同的分配剖析器:hprof,JVisualVM和AProf。有许多不同的剖析器可供选择,包括商业解决方案和免费解决方案,但每种解决方案的功能和优点与以下各节中讨论的类似。
HPROF
与JDK发行版捆绑在一起的是hprof profiler。由于它存在于所有环境中,因此这是第一个在收集信息时要考虑的分析器。
要使用hprof运行应用程序,您需要修改JVM的启动脚本,类似于以下示例:
java -agentlib:hprof = heap = sites com.yourcompany.YourApplication
在应用程序退出时,它会将分配信息转储到java.hprof.txt文件到工作目录。使用您选择的文本编辑器打开文件,并搜索短语“SITES BEGIN”,为您提供类似于以下内容的信息:
SITES BEGIN(以实时字节排序)2015年12月8日星期二11:16:15
百分比实时分配堆栈类
rank self accum bytes objs bytes objs trace name
1 64.43%4.43%8370336 20121 27513408 66138 302116 int []
2 3.26%88.49%482976 20124 1587696 66154 302104 java.util.ArrayList
3 1.76%88.74%241704 20121 1587312 66138 302115 eu.plumbr.demo.largeheap.ClonableClass0006
......为了简洁而切...
站点结束
从上面我们可以看到按每个分配创建的对象数量排名的分配。第一行显示所有对象的64.43%是在由数字302116标识的站点上创建的整数数组(int [])。在文件中搜索“TRACE 302116”可以获得以下信息:
TRACE 302116:
eu.plumbr.demo.largeheap.ClonableClass0006。<初始化>(GeneratorClass.java:11)
sun.reflect.GeneratedConstructorAccessor7.newInstance(<Unknown Source>:Unknown line)
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
java.lang.reflect.Constructor.newInstance(Constructor.java:422)
现在,知道64.43%的对象在ClonableClass0006构造函数中被分配为整数数组,在第11行中,您可以继续优化代码以减轻GC的负担。
Java VisualVM
JVisualVM在本章中再次出现。在第一部分中,我们从监视JVM for GC行为的工具列表中排除了JVisualVM,但在本节中,我们将展示其在分配概要分析方面的优势。
将JVisualVM附加到JVM是通过GUI完成的,您可以将分析器附加到正在运行的JVM。附加探查器后:
- 打开“Profiler”选项卡,确保在“设置”复选框下启用了“记录分配堆栈跟踪”。
- 单击“内存”按钮以启动内存分析。
- 让您的应用程序运行一段时间以收集有关对象分配的足够信息。
- 单击“快照”按钮。这将为您提供所收集的分析信息的快照。
完成上述步骤后,您将看到类似于以下内容的信息:
从上面我们可以看到按每个类创建的对象数量排名的分配。在第一行中,我们可以看到分配的所有对象的绝大多数是int []数组。通过右键单击该行,您可以访问分配了这些对象的所有堆栈跟踪:
与hprof相比,JVisualVM使信息更容易处理 - 例如,在上面的屏幕截图中,您可以看到int []的所有分配跟踪都在单个视图中公开,因此您可以避免可能重复的匹配不同分配的过程痕迹。
AProf
最后,但并非最不重要的是Devexperts的AProf。AProf是打包为Java代理的内存分配分析器。
要使用AProf运行应用程序,您需要修改JVM的启动脚本,类似于以下示例:
java -javaagent:/path-to/aprof.jar com.yourcompany.YourApplication
现在,重新启动应用程序后,将为工作目录创建一个aprof.txt文件。该文件每分钟更新一次,包含类似于以下内容的信息:
================================================== ================================================== ====================
TOTAL分配转储91,289 ms(0h01m31s)
在2,127个地点的425个班级的24,868,088个对象中分配了1,769,670,584个字节
================================================== ================================================== ====================
从其分配的数据类型的最佳分配诱导位置
-------------------------------------------------- -------------------------------------------------- --------------------
eu.plumbr.demo.largeheap.ManyTargetsGarbageProducer.newRandomClassObject:17,113,721(68.81%)个对象中的1,423,675,776(80.44%)个字节(平均大小83个字节)
int []:1,709,911(6.87%)个对象中的711,322,976(40.19%)个字节(平均大小416个字节)
char []:5,132,759(20.63%)个对象中的369,550,816(20.88%)个字节(平均大小为72个字节)
java.lang.reflect.Constructor:1,710,000(6.87%)个对象中的136,800,000(7.73%)字节(平均大小为80字节)
java.lang.Object []:1,710,712(6.87%)个对象中的41,079,872(2.32%)个字节(平均大小为24个字节)
java.lang.String:1,710,979(6.88%)个对象中的41,063,496(2.32%)个字节(平均大小为24个字节)
java.util.ArrayList:1,710,445(6.87%)个对象中的41,050,680(2.31%)个字节(平均大小为24个字节)
......为了简洁而切...
在上面的输出中,分配按大小排序。从上面可以看出,80.44%的字节和68.81%的对象是在ManyTargetsGarbageProducer.newRandomClassObject()方法中分配的。其中,int []数组占用的空间占总内存消耗的40.19%。
向下滚动文件,您将发现具有分配跟踪的块,也按分配大小排序:
具有反向位置跟踪的最高分配数据类型
-------------------------------------------------- -------------------------------------------------- --------------------
int []:1,954,234(7.85%)个对象中的725,306,304(40.98%)个字节(平均大小371个字节)
eu.plumbr.demo.largeheap.ClonableClass0006。:92,206(0.37%)个对象中的38,357,696(2.16%)字节(平均大小416字节)
java.lang.reflect.Constructor.newInstance:92,206(0.37%)个对象中的38,357,696(2.16%)字节(平均大小416字节)
eu.plumbr.demo.largeheap.ManyTargetsGarbageProducer.newRandomClassObject:92,205(0.37%)个对象中的38,357,280(2.16%)个字节(平均大小416个字节)
java.lang.reflect.Constructor.newInstance:1个(0.00%)对象中的416(0.00%)个字节(平均大小416个字节)
......为了简洁而切...
从上面我们可以看到int []数组的分配,再次放大到创建这些数组的ClonableClass0006构造函数。
因此,与其他解决方案一样,AProf公开了有关分配大小和位置的信息,从而可以放大应用程序中最需要内存的部分。但是,在我们看来,AProf是最有用的分配分析器,因为它只关注一件事并且做得非常好。此外,与替代方案相比,这种开源工具是免费的,并且开销最小。