yangjava

Gc调优基础

2016/01/18 JVM

GC 调优(基础篇)

GC调优(Tuning Garbage Collection)和其他性能调优是同样的原理。初学者可能会被 200 多个 GC参数弄得一头雾水, 然后随便调整几个来试试结果,又或者修改几行代码来测试。其实只要参照下面的步骤，就能保证你的调优方向正确:

  1. 列出性能调优指标(State your performance goals)
  2. 执行测试(Run tests)
  3. 检查结果(Measure the results)
  4. 与目标进行对比(Compare the results with the goals)
  5. 如果达不到指标, 修改配置参数, 然后继续测试(go back to running tests)

第一步, 我们需要做的事情就是: 制定明确的GC性能指标。对所有性能监控和管理来说, 有三个维度是通用的:

  • Latency(延迟)
  • Throughput(吞吐量)
  • Capacity(系统容量)

我们先讲解基本概念,然后再演示如何使用这些指标。如果您对 延迟、吞吐量和系统容量等概念很熟悉, 可以跳过这一小节。

核心概念(Core Concepts)

我们先来看一家工厂的装配流水线。工人在流水线将现成的组件按顺序拼接,组装成自行车。通过实地观测, 我们发现从组件进入生产线，到另一端组装成自行车需要4小时。

img

继续观察,我们还发现,此后每分钟就有1辆自行车完成组装, 每天24小时,一直如此。将这个模型简化, 并忽略维护窗口期后得出结论： 这条流水线每小时可以组装60辆自行车。

说明: 时间窗口/窗口期，请类比车站卖票的窗口，是一段规定/限定做某件事的时间段。

通过这两种测量方法, 就知道了生产线的相关性能信息： 延迟与吞吐量:

  • 生产线的延迟: 4小时
  • 生产线的吞吐量: 60辆/小时

请注意, 衡量延迟的时间单位根据具体需要而确定 —— 从纳秒(nanosecond)到几千年(millennia)都有可能。系统的吞吐量是每个单位时间内完成的操作。操作(Operations)一般是特定系统相关的东西。在本例中,选择的时间单位是小时, 操作就是对自行车的组装。

掌握了延迟和吞吐量两个概念之后, 让我们对这个工厂来进行实际的调优。自行车的需求在一段时间内都很稳定, 生产线组装自行车有四个小时延迟, 而吞吐量在几个月以来都很稳定: 60辆/小时。假设某个销售团队突然业绩暴涨, 对自行车的需求增加了1倍。客户每天需要的自行车不再是 60 * 24 = 1440辆, 而是 2*1440 = 2880辆/天。老板对工厂的产能不满意，想要做些调整以提升产能。

看起来总经理很容易得出正确的判断, 系统的延迟没法子进行处理 —— 他关注的是每天的自行车生产总量。得出这个结论以后, 假若工厂资金充足, 那么应该立即采取措施, 改善吞吐量以增加产能。

我们很快会看到, 这家工厂有两条相同的生产线。每条生产线一分钟可以组装一辆成品自行车。 可以想象，每天生产的自行车数量会增加一倍。达到 2880辆/天。要注意的是, 不需要减少自行车的装配时间 —— 从开始到结束依然需要 4 小时。

img

巧合的是，这样进行的性能优化,同时增加了吞吐量和产能。一般来说，我们会先测量当前的系统性能, 再设定新目标, 只优化系统的某个方面来满足性能指标。

在这里做了一个很重要的决定 —— 要增加吞吐量,而不是减小延迟。在增加吞吐量的同时, 也需要增加系统容量。比起原来的情况, 现在需要两条流水线来生产出所需的自行车。在这种情况下, 增加系统的吞吐量并不是免费的, 需要水平扩展, 以满足增加的吞吐量需求。

在处理性能问题时, 应该考虑到还有另一种看似不相关的解决办法。假如生产线的延迟从1分钟降低为30秒,那么吞吐量同样可以增长 1 倍。

或者是降低延迟, 或者是客户非常有钱。软件工程里有一种相似的说法 —— 每个性能问题背后,总有两种不同的解决办法。 可以用更多的机器, 或者是花精力来改善性能低下的代码。

Latency(延迟)

GC的延迟指标由一般的延迟需求决定。延迟指标通常如下所述:

  • 所有交易必须在10秒内得到响应
  • 90%的订单付款操作必须在3秒以内处理完成
  • 推荐商品必须在 100 ms 内展示到用户面前

面对这类性能指标时, 需要确保在交易过程中, GC暂停不能占用太多时间，否则就满足不了指标。“不能占用太多” 的意思需要视具体情况而定, 还要考虑到其他因素, 比如外部数据源的交互时间(round-trips), 锁竞争(lock contention), 以及其他的安全点等等。

假设性能需求为: 90%的交易要在 1000ms 以内完成, 每次交易最长不能超过 10秒。 根据经验, 假设GC暂停时间比例不能超过10%。 也就是说, 90%的GC暂停必须在 100ms 内结束, 也不能有超过 1000ms 的GC暂停。为简单起见, 我们忽略在同一次交易过程中发生多次GC停顿的可能性。

有了正式的需求,下一步就是检查暂停时间。在本节中我们通过查看GC日志, 检查一下GC暂停的时间。相关的信息散落在不同的日志片段中, 看下面的数据:

2015-06-04T13:34:16.974-0200: 2.578: [Full GC (Ergonomics)
        [PSYoungGen: 93677K->70109K(254976K)]
        [ParOldGen: 499597K->511230K(761856K)]
        593275K->581339K(1016832K),
        [Metaspace: 2936K->2936K(1056768K)]
    , 0.0713174 secs]
    [Times: user=0.21 sys=0.02, real=0.07 secs

这表示一次GC暂停, 在 2015-06-04T13:34:16 这个时刻触发. 对应于JVM启动之后的 2,578 ms。

此事件将应用线程暂停了 0.0713174 秒。虽然花费的总时间为 210 ms, 但因为是多核CPU机器, 所以最重要的数字是应用线程被暂停的总时间, 这里使用的是并行GC, 所以暂停时间大约为 70ms 。 这次GC的暂停时间小于 100ms 的阈值，满足需求。

继续分析, 从所有GC日志中提取出暂停相关的数据, 汇总之后就可以得知是否满足需求。

Throughput(吞吐量)

吞吐量和延迟指标有很大区别。当然两者都是根据一般吞吐量需求而得出的。一般吞吐量需求(Generic requirements for throughput) 类似这样:

  • 解决方案每天必须处理 100万个订单
  • 解决方案必须支持1000个登录用户,同时在5-10秒内执行某个操作: A、B或C
  • 每周对所有客户进行统计, 时间不能超过6小时，时间窗口为每周日晚12点到次日6点之间。

可以看出,吞吐量需求不是针对单个操作的, 而是在给定的时间内, 系统必须完成多少个操作。和延迟需求类似, GC调优也需要确定GC行为所消耗的总时间。每个系统能接受的时间不同, 一般来说, GC占用的总时间比不能超过 10%。

现在假设需求为: 每分钟处理 1000 笔交易。同时, 每分钟GC暂停的总时间不能超过6秒(即10%)。

有了正式的需求, 下一步就是获取相关的信息。依然是从GC日志中提取数据, 可以看到类似这样的信息:

2015-06-04T13:34:16.974-0200: 2.578: [Full GC (Ergonomics)
        [PSYoungGen: 93677K->70109K(254976K)]
        [ParOldGen: 499597K->511230K(761856K)]
        593275K->581339K(1016832K),
        [Metaspace: 2936K->2936K(1056768K)],
     0.0713174 secs]
     [Times: user=0.21 sys=0.02, real=0.07 secs

此时我们对 用户耗时(user)和系统耗时(sys)感兴趣, 而不关心实际耗时(real)。在这里, 我们关心的时间为 0.23s(user + sys = 0.21 + 0.02 s), 这段时间内, GC暂停占用了 cpu 资源。 重要的是, 系统运行在多核机器上, 转换为实际的停顿时间(stop-the-world)为 0.0713174秒, 下面的计算会用到这个数字。

提取出有用的信息后, 剩下要做的就是统计每分钟内GC暂停的总时间。看看是否满足需求: 每分钟内总的暂停时间不得超过6000毫秒(6秒)。

Capacity(系统容量)

系统容量(Capacity)需求,是在达成吞吐量和延迟指标的情况下,对硬件环境的额外约束。这类需求大多是来源于计算资源或者预算方面的原因。例如:

  • 系统必须能部署到小于512 MB内存的Android设备上
  • 系统必须部署在Amazon EC2实例上, 配置不得超过 c3.xlarge(4核8GB)。
  • 每月的 Amazon EC2 账单不得超过 $12,000

因此, 在满足延迟和吞吐量需求的基础上必须考虑系统容量。可以说, 假若有无限的计算资源可供挥霍, 那么任何 延迟和吞吐量指标 都不成问题, 但现实情况是, 预算(budget)和其他约束限制了可用的资源。

相关示例

介绍完性能调优的三个维度后, 我们来进行实际的操作以达成GC性能指标。

请看下面的代码:

//imports skipped for brevity
public class Producer implements Runnable {

  private static ScheduledExecutorService executorService
         = Executors.newScheduledThreadPool(2);

  private Deque<byte[]> deque;
  private int objectSize;
  private int queueSize;

  public Producer(int objectSize, int ttl) {
    this.deque = new ArrayDeque<byte[]>();
    this.objectSize = objectSize;
    this.queueSize = ttl * 1000;
  }

  @Override
  public void run() {
    for (int i = 0; i < 100; i++) {
        deque.add(new byte[objectSize]);
        if (deque.size() > queueSize) {
            deque.poll();
        }
    }
  }

  public static void main(String[] args)
        throws InterruptedException {
    executorService.scheduleAtFixedRate(
        new Producer(200 * 1024 * 1024 / 1000, 5),
        0, 100, TimeUnit.MILLISECONDS
    );
    executorService.scheduleAtFixedRate(
        new Producer(50 * 1024 * 1024 / 1000, 120),
        0, 100, TimeUnit.MILLISECONDS);
    TimeUnit.MINUTES.sleep(10);
    executorService.shutdownNow();}}

这段程序代码, 每 100毫秒 提交两个作业(job)来。每个作业都模拟特定的生命周期: 创建对象, 然后在预定的时间释放, 接着就不管了, 由GC来自动回收占用的内存。

在运行这个示例程序时，通过以下JVM参数打开GC日志记录:

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps

还应该加上JVM参数 -Xloggc以指定GC日志的存储位置,类似这样:

-Xloggc:C:\\Producer_gc.log

在日志文件中可以看到GC的行为, 类似下面这样:

2015-06-04T13:34:16.119-0200: 1.723: [GC (Allocation Failure)
        [PSYoungGen: 114016K->73191K(234496K)]
    421540K->421269K(745984K),
    0.0858176 secs]
    [Times: user=0.04 sys=0.06, real=0.09 secs]

2015-06-04T13:34:16.738-0200: 2.342: [GC (Allocation Failure)
        [PSYoungGen: 234462K->93677K(254976K)]
    582540K->593275K(766464K),
    0.2357086 secs]
    [Times: user=0.11 sys=0.14, real=0.24 secs]

2015-06-04T13:34:16.974-0200: 2.578: [Full GC (Ergonomics)
        [PSYoungGen: 93677K->70109K(254976K)]
        [ParOldGen: 499597K->511230K(761856K)]
    593275K->581339K(1016832K),
        [Metaspace: 2936K->2936K(1056768K)],
    0.0713174 secs]
    [Times: user=0.21 sys=0.02, real=0.07 secs]

基于日志中的信息, 可以通过三个优化目标来提升性能:

  1. 确保最坏情况下,GC暂停时间不超过预定阀值
  2. 确保线程暂停的总时间不超过预定阀值
  3. 在确保达到延迟和吞吐量指标的情况下, 降低硬件配置以及成本。

为此, 用三种不同的配置, 将代码运行10分钟, 得到了三种不同的结果, 汇总如下:

堆内存大小(Heap) GC算法(GC Algorithm) 有效时间比(Useful work) 最长停顿时间(Longest pause)
-Xmx12g -XX:+UseConcMarkSweepGC 89.8% 560 ms
-Xmx12g -XX:+UseParallelGC 91.5% 1,104 ms
-Xmx8g -XX:+UseConcMarkSweepGC 66.3% 1,610 ms

使用不同的GC算法,和不同的内存配置,运行相同的代码, 以测量GC暂停时间与 延迟、吞吐量的关系。实验的细节和结果在后面章节详细介绍。

注意, 为了尽量简单, 示例中只改变了很少的输入参数, 此实验也没有在不同CPU数量或者不同的堆布局下进行测试。

Tuning for Latency(调优延迟指标)

假设有一个需求, 每次作业必须在 1000ms 内处理完成。我们知道, 实际的作业处理只需要100 ms，简化后， 两者相减就可以算出对 GC暂停的延迟要求。现在需求变成: GC暂停不能超过900ms。这个问题很容易找到答案, 只需要解析GC日志文件, 并找出GC暂停中最大的那个暂停时间即可。

再来看测试所用的三个配置:

堆内存大小(Heap) GC算法(GC Algorithm) 有效时间比(Useful work) 最长停顿时间(Longest pause)
-Xmx12g -XX:+UseConcMarkSweepGC 89.8% 560 ms
-Xmx12g -XX:+UseParallelGC 91.5% 1,104 ms
-Xmx8g -XX:+UseConcMarkSweepGC 66.3% 1,610 ms

可以看到,其中有一个配置达到了要求。运行的参数为:

java -Xmx12g -XX:+UseConcMarkSweepGC Producer

对应的GC日志中,暂停时间最大为 560 ms, 这达到了延迟指标 900 ms 的要求。如果还满足吞吐量和系统容量需求的话,就可以说成功达成了GC调优目标, 调优结束。

Tuning for Throughput(吞吐量调优)

假定吞吐量指标为: 每小时完成 1300万次操作处理。同样是上面的配置, 其中有一种配置满足了需求:

堆内存大小(Heap) GC算法(GC Algorithm) 有效时间比(Useful work) 最长停顿时间(Longest pause)
-Xmx12g -XX:+UseConcMarkSweepGC 89.8% 560 ms
-Xmx12g -XX:+UseParallelGC 91.5% 1,104 ms
-Xmx8g -XX:+UseConcMarkSweepGC 66.3% 1,610 ms

此配置对应的命令行参数为:

java -Xmx12g -XX:+UseParallelGC Producer

可以看到,GC占用了 8.5%的CPU时间,剩下的 91.5% 是有效的计算时间。为简单起见, 忽略示例中的其他安全点。现在需要考虑:

  1. 每个CPU核心处理一次作业需要耗时 100ms
  2. 因此, 一分钟内每个核心可以执行 60,000 次操作(每个job完成100次操作)
  3. 一小时内, 一个核心可以执行 360万次操作
  4. 有四个CPU内核, 则每小时可以执行: 4 x 3.6M = 1440万次操作

理论上，通过简单的计算就可以得出结论, 每小时可以执行的操作数为: 14.4 M * 91.5% = 13,176,000 次, 满足需求。

值得一提的是, 假若还要满足延迟指标, 那就有问题了, 最坏情况下, GC暂停时间为 1,104 ms, 最大延迟时间是前一种配置的两倍。

Tuning for Capacity(调优系统容量)

假设需要将软件部署到服务器上(commodity-class hardware), 配置为 4核10G。这样的话, 系统容量的要求就变成: 最大的堆内存空间不能超过 8GB。有了这个需求, 我们需要调整为第三套配置进行测试:

堆内存大小(Heap) GC算法(GC Algorithm) 有效时间比(Useful work) 最长停顿时间(Longest pause)
-Xmx12g -XX:+UseConcMarkSweepGC 89.8% 560 ms
-Xmx12g -XX:+UseParallelGC 91.5% 1,104 ms
-Xmx8g -XX:+UseConcMarkSweepGC 66.3% 1,610 ms

程序可以通过如下参数执行:

java -Xmx8g -XX:+UseConcMarkSweepGC Producer

测试结果是延迟大幅增长, 吞吐量同样大幅降低:

  • 现在,GC占用了更多的CPU资源, 这个配置只有 66.3% 的有效CPU时间。因此,这个配置让吞吐量从最好的情况 13,176,000 操作/小时 下降到 不足 9,547,200次操作/小时.
  • 最坏情况下的延迟变成了 1,610 ms, 而不再是 560ms。

通过对这三个维度的介绍, 你应该了解, 不是简单的进行“性能(performance)”优化, 而是需要从三种不同的维度来进行考虑, 测量, 并调优延迟和吞吐量, 此外还需要考虑系统容量的约束。

GC 调优(命令篇)

运用jvm自带的命令可以方便的在生产监控和打印堆栈的日志信息帮忙我们来定位问题！虽然jvm调优成熟的工具已经有很多：jconsole、大名鼎鼎的VisualVM，IBM的Memory Analyzer等等，但是在生产环境出现问题的时候，一方面工具的使用会有所限制，另一方面喜欢装X的我们，总喜欢在出现问题的时候在终端输入一些命令来解决。所有的工具几乎都是依赖于jdk的接口和底层的这些命令，研究这些命令的使用也让我们更能了解jvm构成和特性。

Sun JDK监控和故障处理命令有jps jstat jmap jhat jstack jinfo下面做一一介绍

jps

JVM Process Status Tool,显示指定系统内所有的HotSpot虚拟机进程。

命令格式

jps [options] [hostid]

option参数

  • -l : 输出主类全名或jar路径
  • -q : 只输出LVMID
  • -m : 输出JVM启动时传递给main()的参数
  • -v : 输出JVM启动时显示指定的JVM参数

其中[option]、[hostid]参数也可以不写。

示例

$ jps -l -m
  28920 org.apache.catalina.startup.Bootstrap start
  11589 org.apache.catalina.startup.Bootstrap start
  25816 sun.tools.jps.Jps -l -m

jstat

jstat(JVM statistics Monitoring)是用于监视虚拟机运行时状态信息的命令，它可以显示出虚拟机进程中的类装载、内存、垃圾收集、JIT编译等运行数据。

命令格式

jstat [option] LVMID [interval] [count]

参数

  • [option] : 操作参数
  • LVMID : 本地虚拟机进程ID
  • [interval] : 连续输出的时间间隔
  • [count] : 连续输出的次数

option 参数总览

Option Displays…
class class loader的行为统计。Statistics on the behavior of the class loader.
compiler HotSpt JIT编译器行为统计。Statistics of the behavior of the HotSpot Just-in-Time compiler.
gc 垃圾回收堆的行为统计。Statistics of the behavior of the garbage collected heap.
gccapacity 各个垃圾回收代容量(young,old,perm)和他们相应的空间统计。Statistics of the capacities of the generations and their corresponding spaces.
gcutil 垃圾回收统计概述。Summary of garbage collection statistics.
gccause 垃圾收集统计概述（同-gcutil），附加最近两次垃圾回收事件的原因。Summary of garbage collection statistics (same as -gcutil), with the cause of the last and
gcnew 新生代行为统计。Statistics of the behavior of the new generation.
gcnewcapacity 新生代与其相应的内存空间的统计。Statistics of the sizes of the new generations and its corresponding spaces.
gcold 年老代和永生代行为统计。Statistics of the behavior of the old and permanent generations.
gcoldcapacity 年老代行为统计。Statistics of the sizes of the old generation.
gcpermcapacity 永生代行为统计。Statistics of the sizes of the permanent generation.
printcompilation HotSpot编译方法统计。HotSpot compilation method statistics.

option 参数详解

-class

监视类装载、卸载数量、总空间以及耗费的时间

$ jstat -class 11589
 Loaded  Bytes  Unloaded  Bytes     Time   
  7035  14506.3     0     0.0       3.67
  • Loaded : 加载class的数量
  • Bytes : class字节大小
  • Unloaded : 未加载class的数量
  • Bytes : 未加载class的字节大小
  • Time : 加载时间
-compiler

输出JIT编译过的方法数量耗时等

$ jstat -compiler 1262
Compiled Failed Invalid   Time   FailedType FailedMethod
    2573      1       0    47.60          1 org/apache/catalina/loader/WebappClassLoader findResourceInternal
  • Compiled : 编译数量
  • Failed : 编译失败数量
  • Invalid : 无效数量
  • Time : 编译耗时
  • FailedType : 失败类型
  • FailedMethod : 失败方法的全限定名
-gc

垃圾回收堆的行为统计，常用命令

$ jstat -gc 1262
 S0C    S1C     S0U     S1U   EC       EU        OC         OU        PC       PU         YGC    YGCT    FGC    FGCT     GCT   
26112.0 24064.0 6562.5  0.0   564224.0 76274.5   434176.0   388518.3  524288.0 42724.7    320    6.417   1      0.398    6.815

C即Capacity 总容量，U即Used 已使用的容量

  • S0C : survivor0区的总容量
  • S1C : survivor1区的总容量
  • S0U : survivor0区已使用的容量
  • S1U : survivor1区已使用的容量
  • EC : Eden区的总容量
  • EU : Eden区已使用的容量
  • OC : Old区的总容量
  • OU : Old区已使用的容量
  • PC 当前perm的容量 (KB)
  • PU perm的使用 (KB)
  • YGC : 新生代垃圾回收次数
  • YGCT : 新生代垃圾回收时间
  • FGC : 老年代垃圾回收次数
  • FGCT : 老年代垃圾回收时间
  • GCT : 垃圾回收总消耗时间
$ jstat -gc 1262 2000 20

这个命令意思就是每隔2000ms输出1262的gc情况，一共输出20次

-gccapacity

同-gc，不过还会输出Java堆各区域使用到的最大、最小空间

$ jstat -gccapacity 1262
 NGCMN    NGCMX     NGC    S0C   S1C       EC         OGCMN      OGCMX      OGC        OC       PGCMN    PGCMX     PGC      PC         YGC    FGC 
614400.0 614400.0 614400.0 26112.0 24064.0 564224.0   434176.0   434176.0   434176.0   434176.0 524288.0 1048576.0 524288.0 524288.0    320     1
  • NGCMN : 新生代占用的最小空间
  • NGCMX : 新生代占用的最大空间
  • OGCMN : 老年代占用的最小空间
  • OGCMX : 老年代占用的最大空间
  • OGC：当前年老代的容量 (KB)
  • OC：当前年老代的空间 (KB)
  • PGCMN : perm占用的最小空间
  • PGCMX : perm占用的最大空间
-gcutil

同-gc，不过输出的是已使用空间占总空间的百分比

$ jstat -gcutil 28920
  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT   
 12.45   0.00  33.85   0.00   4.44  4       0.242     0    0.000    0.242
-gccause

垃圾收集统计概述（同-gcutil），附加最近两次垃圾回收事件的原因

$ jstat -gccause 28920
  S0     S1     E      O      P       YGC     YGCT    FGC    FGCT     GCT    LGCC                 GCC                 
 12.45   0.00  33.85   0.00   4.44      4    0.242     0    0.000    0.242   Allocation Failure   No GC
  • LGCC：最近垃圾回收的原因
  • GCC：当前垃圾回收的原因
-gcnew

统计新生代的行为

$ jstat -gcnew 28920
 S0C      S1C      S0U        S1U  TT  MTT  DSS      EC        EU         YGC     YGCT  
 419392.0 419392.0 52231.8    0.0  6   6    209696.0 3355520.0 1172246.0  4       0.242
  • TT：Tenuring threshold(提升阈值)
  • MTT：最大的tenuring threshold
  • DSS：survivor区域大小 (KB)
-gcnewcapacity

新生代与其相应的内存空间的统计

$ jstat -gcnewcapacity 28920
  NGCMN      NGCMX       NGC      S0CMX     S0C     S1CMX     S1C       ECMX        EC        YGC   FGC 
 4194304.0  4194304.0  4194304.0 419392.0 419392.0 419392.0 419392.0  3355520.0  3355520.0     4     0
  • NGC:当前年轻代的容量 (KB)
  • S0CMX:最大的S0空间 (KB)
  • S0C:当前S0空间 (KB)
  • ECMX:最大eden空间 (KB)
  • EC:当前eden空间 (KB)
-gcold

统计旧生代的行为

$ jstat -gcold 28920
   PC       PU        OC           OU       YGC    FGC    FGCT     GCT   
1048576.0  46561.7   6291456.0     0.0      4      0      0.000    0.242
-gcoldcapacity

统计旧生代的大小和空间

$ jstat -gcoldcapacity 28920
   OGCMN       OGCMX        OGC         OC         YGC   FGC    FGCT     GCT   
  6291456.0   6291456.0   6291456.0   6291456.0     4     0    0.000    0.242
-gcpermcapacity

永生代行为统计

$ jstat -gcpermcapacity 28920
    PGCMN      PGCMX       PGC         PC      YGC   FGC    FGCT     GCT   
 1048576.0  2097152.0  1048576.0  1048576.0     4     0    0.000    0.242
-printcompilation

hotspot编译方法统计

$ jstat -printcompilation 28920
    Compiled  Size  Type Method
    1291      78     1    java/util/ArrayList indexOf
  • Compiled：被执行的编译任务的数量
  • Size：方法字节码的字节数
  • Type：编译类型
  • Method：编译方法的类名和方法名。类名使用”/” 代替 “.” 作为空间分隔符. 方法名是给出类的方法名. 格式是一致于HotSpot - XX:+PrintComplation 选项

jmap

jmap(JVM Memory Map)命令用于生成heap dump文件，如果不使用这个命令，还阔以使用-XX:+HeapDumpOnOutOfMemoryError参数来让虚拟机出现OOM的时候·自动生成dump文件。 jmap不仅能生成dump文件，还阔以查询finalize执行队列、Java堆和永久代的详细信息，如当前使用率、当前使用的是哪种收集器等。

命令格式

jmap [option] LVMID

option参数

  • dump : 生成堆转储快照
  • finalizerinfo : 显示在F-Queue队列等待Finalizer线程执行finalizer方法的对象
  • heap : 显示Java堆详细信息
  • histo : 显示堆中对象的统计信息
  • permstat : to print permanent generation statistics
  • F : 当-dump没有响应时，强制生成dump快照

示例

-dump

常用格式

-dump::live,format=b,file=<filename> pid

dump堆到文件,format指定输出格式，live指明是活着的对象,file指定文件名

$ jmap -dump:live,format=b,file=dump.hprof 28920
  Dumping heap to /home/xxx/dump.hprof ...
  Heap dump file created

dump.hprof这个后缀是为了后续可以直接用MAT(Memory Anlysis Tool)打开。

-finalizerinfo

打印等待回收对象的信息

$ jmap -finalizerinfo 28920
  Attaching to process ID 28920, please wait...
  Debugger attached successfully.
  Server compiler detected.
  JVM version is 24.71-b01
  Number of objects pending for finalization: 0

可以看到当前F-QUEUE队列中并没有等待Finalizer线程执行finalizer方法的对象。

-heap

打印heap的概要信息，GC使用的算法，heap的配置及wise heap的使用情况,可以用此来判断内存目前的使用情况以及垃圾回收情况

$ jmap -heap 28920
  Attaching to process ID 28920, please wait...
  Debugger attached successfully.
  Server compiler detected.
  JVM version is 24.71-b01  

  using thread-local object allocation.
  Parallel GC with 4 thread(s)//GC 方式  

  Heap Configuration: //堆内存初始化配置
     MinHeapFreeRatio = 0 //对应jvm启动参数-XX:MinHeapFreeRatio设置JVM堆最小空闲比率(default 40)
     MaxHeapFreeRatio = 100 //对应jvm启动参数 -XX:MaxHeapFreeRatio设置JVM堆最大空闲比率(default 70)
     MaxHeapSize      = 2082471936 (1986.0MB) //对应jvm启动参数-XX:MaxHeapSize=设置JVM堆的最大大小
     NewSize          = 1310720 (1.25MB)//对应jvm启动参数-XX:NewSize=设置JVM堆的‘新生代’的默认大小
     MaxNewSize       = 17592186044415 MB//对应jvm启动参数-XX:MaxNewSize=设置JVM堆的‘新生代’的最大大小
     OldSize          = 5439488 (5.1875MB)//对应jvm启动参数-XX:OldSize=<value>:设置JVM堆的‘老生代’的大小
     NewRatio         = 2 //对应jvm启动参数-XX:NewRatio=:‘新生代’和‘老生代’的大小比率
     SurvivorRatio    = 8 //对应jvm启动参数-XX:SurvivorRatio=设置年轻代中Eden区与Survivor区的大小比值 
     PermSize         = 21757952 (20.75MB)  //对应jvm启动参数-XX:PermSize=<value>:设置JVM堆的‘永生代’的初始大小
     MaxPermSize      = 85983232 (82.0MB)//对应jvm启动参数-XX:MaxPermSize=<value>:设置JVM堆的‘永生代’的最大大小
     G1HeapRegionSize = 0 (0.0MB)  

  Heap Usage://堆内存使用情况
  PS Young Generation
  Eden Space://Eden区内存分布
     capacity = 33030144 (31.5MB)//Eden区总容量
     used     = 1524040 (1.4534378051757812MB)  //Eden区已使用
     free     = 31506104 (30.04656219482422MB)  //Eden区剩余容量
     4.614088270399305% used //Eden区使用比率
  From Space:  //其中一个Survivor区的内存分布
     capacity = 5242880 (5.0MB)
     used     = 0 (0.0MB)
     free     = 5242880 (5.0MB)
     0.0% used
  To Space:  //另一个Survivor区的内存分布
     capacity = 5242880 (5.0MB)
     used     = 0 (0.0MB)
     free     = 5242880 (5.0MB)
     0.0% used
  PS Old Generation //当前的Old区内存分布
     capacity = 86507520 (82.5MB)
     used     = 0 (0.0MB)
     free     = 86507520 (82.5MB)
     0.0% used
  PS Perm Generation//当前的 “永生代” 内存分布
     capacity = 22020096 (21.0MB)
     used     = 2496528 (2.3808746337890625MB)
     free     = 19523568 (18.619125366210938MB)
     11.337498256138392% used  

  670 interned Strings occupying 43720 bytes.

可以很清楚的看到Java堆中各个区域目前的情况。

-histo

打印堆的对象统计，包括对象数、内存大小等等 （因为在dump:live前会进行full gc，如果带上live则只统计活对象，因此不加live的堆大小要大于加live堆的大小 ）

$ jmap -histo:live 28920 | more
 num     #instances         #bytes  class name
----------------------------------------------
   1:         83613       12012248  <constMethodKlass>
   2:         23868       11450280  [B
   3:         83613       10716064  <methodKlass>
   4:         76287       10412128  [C
   5:          8227        9021176  <constantPoolKlass>
   6:          8227        5830256  <instanceKlassKlass>
   7:          7031        5156480  <constantPoolCacheKlass>
   8:         73627        1767048  java.lang.String
   9:          2260        1348848  <methodDataKlass>
  10:          8856         849296  java.lang.Class
  ....

仅仅打印了前10行

xml class name是对象类型，说明如下：

B  byte
C  char
D  double
F  float
I  int
J  long
Z  boolean
[  数组，如[I表示int[]
[L+类名 其他对象
-permstat

打印Java堆内存的永久保存区域的类加载器的智能统计信息。对于每个类加载器而言，它的名称、活跃度、地址、父类加载器、它所加载的类的数量和大小都会被打印。此外，包含的字符串数量和大小也会被打印。

$ jmap -permstat 28920
  Attaching to process ID 28920, please wait...
  Debugger attached successfully.
  Server compiler detected.
  JVM version is 24.71-b01
  finding class loader instances ..done.
  computing per loader stat ..done.
  please wait.. computing liveness.liveness analysis may be inaccurate ...
  
  class_loader            classes bytes   parent_loader           alive?  type  
  <bootstrap>             3111    18154296          null          live    <internal>
  0x0000000600905cf8      1       1888    0x0000000600087f08      dead    sun/reflect/DelegatingClassLoader@0x00000007800500a0
  0x00000006008fcb48      1       1888    0x0000000600087f08      dead    sun/reflect/DelegatingClassLoader@0x00000007800500a0
  0x00000006016db798      0       0       0x00000006008d3fc0      dead    java/util/ResourceBundle$RBClassLoader@0x0000000780626ec0
  0x00000006008d6810      1       3056      null          dead    sun/reflect/DelegatingClassLoader@0x00000007800500a0
-F

强制模式。如果指定的pid没有响应，请使用jmap -dump或jmap -histo选项。此模式下，不支持live子选项。

jhat

jhat(JVM Heap Analysis Tool)命令是与jmap搭配使用，用来分析jmap生成的dump，jhat内置了一个微型的HTTP/HTML服务器，生成dump的分析结果后，可以在浏览器中查看。在此要注意，一般不会直接在服务器上进行分析，因为jhat是一个耗时并且耗费硬件资源的过程，一般把服务器生成的dump文件复制到本地或其他机器上进行分析。

命令格式

jhat [dumpfile]

参数

  • -stack false true 关闭对象分配调用栈跟踪(tracking object allocation call stack)。 如果分配位置信息在堆转储中不可用. 则必须将此标志设置为 false. 默认值为 true.>
  • -refs false true 关闭对象引用跟踪(tracking of references to objects)。 默认值为 true. 默认情况下, 返回的指针是指向其他特定对象的对象,如反向链接或输入引用(referrers or incoming references), 会统计/计算堆中的所有对象。>
  • -port port-number 设置 jhat HTTP server 的端口号. 默认值 7000.>
  • -exclude exclude-file 指定对象查询时需要排除的数据成员列表文件(a file that lists data members that should be excluded from the reachable objects query)。 例如, 如果文件列列出了 java.lang.String.value , 那么当从某个特定对象 Object o 计算可达的对象列表时, 引用路径涉及 java.lang.String.value 的都会被排除。>
  • -baseline exclude-file 指定一个基准堆转储(baseline heap dump)。 在两个 heap dumps 中有相同 object ID 的对象会被标记为不是新的(marked as not being new). 其他对象被标记为新的(new). 在比较两个不同的堆转储时很有用.>
  • -debug int 设置 debug 级别. 0 表示不输出调试信息。 值越大则表示输出更详细的 debug 信息.>
  • -version 启动后只显示版本信息就退出>
  • -J< flag > 因为 jhat 命令实际上会启动一个JVM来执行, 通过 -J 可以在启动JVM时传入一些启动参数. 例如, -J-Xmx512m 则指定运行 jhat 的Java虚拟机使用的最大堆内存为 512 MB. 如果需要使用多个JVM启动参数,则传入多个 -Jxxxxxx.

示例

$ jhat -J-Xmx512m dump.hprof
  eading from dump.hprof...
  Dump file created Fri Mar 11 17:13:42 CST 2016
  Snapshot read, resolving...
  Resolving 271678 objects...
  Chasing references, expect 54 dots......................................................
  Eliminating duplicate references......................................................
  Snapshot resolved.
  Started HTTP server on port 7000
  Server is ready.

中间的-J-Xmx512m是在dump快照很大的情况下分配512M内存去启动HTTP服务器，运行完之后就可在浏览器打开Http://localhost:7000进行快照分析 堆快照分析主要在最后面的Heap Histogram里，里面根据class列出了dump的时候所有存活对象。

分析同样一个dump快照，MAT需要的额外内存比jhat要小的多的多，所以建议使用MAT来进行分析，当然也看个人偏好。

分析

打开浏览器Http://localhost:7000，该页面提供了几个查询功能可供使用：

All classes including platform
Show all members of the rootset
Show instance counts for all classes (including platform)
Show instance counts for all classes (excluding platform)
Show heap histogram
Show finalizer summary
Execute Object Query Language (OQL) query

一般查看堆异常情况主要看这个两个部分： Show instance counts for all classes (excluding platform)，平台外的所有对象信息。如下图：img Show heap histogram 以树状图形式展示堆情况。如下图：img 具体排查时需要结合代码，观察是否大量应该被回收的对象在一直被引用或者是否有占用内存特别大的对象无法被回收。 一般情况，会down到客户端用工具来分析

jstack

jstack用于生成java虚拟机当前时刻的线程快照。线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合，生成线程快照的主要目的是定位线程出现长时间停顿的原因，如线程间死锁、死循环、请求外部资源导致的长时间等待等。 线程出现停顿的时候通过jstack来查看各个线程的调用堆栈，就可以知道没有响应的线程到底在后台做什么事情，或者等待什么资源。 如果java程序崩溃生成core文件，jstack工具可以用来获得core文件的java stack和native stack的信息，从而可以轻松地知道java程序是如何崩溃和在程序何处发生问题。另外，jstack工具还可以附属到正在运行的java程序中，看到当时运行的java程序的java stack和native stack的信息, 如果现在运行的java程序呈现hung的状态，jstack是非常有用的。

命令格式

jstack [option] LVMID

option参数

  • -F : 当正常输出请求不被响应时，强制输出线程堆栈
  • -l : 除堆栈外，显示关于锁的附加信息
  • -m : 如果调用到本地方法的话，可以显示C/C++的堆栈

Jstack -l PID » 123.txt 在发生死锁时可以用jstack -l pid来观察锁持有情况 »123.txt dump到指定文件

示例

$ jstack -l 11494|more
2016-07-28 13:40:04
Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.71-b01 mixed mode):

"Attach Listener" daemon prio=10 tid=0x00007febb0002000 nid=0x6b6f waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
        - None

"http-bio-8005-exec-2" daemon prio=10 tid=0x00007feb94028000 nid=0x7b8c waiting on condition [0x00007fea8f56e000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000cae09b80> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
        at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
        - None
      .....

https://www.hollischuang.com/archives/110

分析

这里有一篇文章解释的很好 分析打印出的文件内容

https://www.hollischuang.com/archives/110

jinfo

jinfo(JVM Configuration info)这个命令作用是实时查看和调整虚拟机运行参数。 之前的jps -v口令只能查看到显示指定的参数，如果想要查看未被显示指定的参数的值就要使用jinfo口令

命令格式

jinfo [option] [args] LVMID

option参数

  • -flag : 输出指定args参数的值
  • -flags : 不需要args参数，输出所有JVM参数的值
  • -sysprops : 输出系统属性，等同于System.getProperties()

示例

Java开发必须掌握的线上问题排查命令

正文

作为一个合格的开发人员，不仅要能写得一手还代码，还有一项很重要的技能就是排查问题。这里提到的排查问题不仅仅是在coding的过程中debug等，还包括的就是线上问题的排查。由于在生产环境中，一般没办法debug（其实有些问题，debug也白扯。。。）,所以我们需要借助一些常用命令来查看运行时的具体情况，这些运行时信息包括但不限于运行日志、异常堆栈、堆使用情况、GC情况、JVM参数情况、线程情况等。

给一个系统定位问题的时候，知识、经验是关键，数据是依据，工具是运用知识处理数据的手段。为了便于我们排查和解决问题，Sun公司为我们提供了一些常用命令。这些命令一般都是jdk/lib/tools.jar中类库的一层薄包装。随着JVM的安装一起被安装到机器中，在bin目录中。下面就来认识一下这些命令以及具体使用方式。文中涉及到的所有命令的详细信息可以参考 Java命令学习系列文章

jps

功能

显示当前所有java进程pid的命令。

常用指令

jps：显示当前用户的所有java进程的PID

jps -v 3331：显示虚拟机参数

jps -m 3331：显示传递给main()函数的参数

jps -l 3331：显示主类的全路径

详细介绍

回到顶部

jinfo

功能

实时查看和调整虚拟机参数，可以显示未被显示指定的参数的默认值（jps -v 则不能）。

jdk8中已经不支持该命令。

常用指令

jinfo -flag CMSIniniatingOccupancyFration 1444：查询CMSIniniatingOccupancyFration参数值

详细介绍

回到顶部

jstat

功能

显示进程中的类装载、内存、垃圾收集、JIT编译等运行数据。

常用指令

jstat -gc 3331 250 20 ：查询进程2764的垃圾收集情况，每250毫秒查询一次，一共查询20次。

jstat -gccause：额外输出上次GC原因

jstat -calss：件事类装载、类卸载、总空间以及所消耗的时间

详细介绍

回到顶部

jmap

功能

生成堆转储快照（heapdump）

常用指令

jmap -heap 3331：查看java 堆（heap）使用情况

jmap -histo 3331：查看堆内存(histogram)中的对象数量及大小

jmap -histo:live 3331：JVM会先触发gc，然后再统计信息

jmap -dump:format=b,file=heapDump 3331：将内存使用的详细情况输出到文件，之后一般使用其他工具进行分析。

详细介绍

回到顶部

jhat

功能

一般与jmap搭配使用，用来分析jmap生成的堆转储文件。

由于有很多可视化工具（Eclipse Memory Analyzer 、IBM HeapAnalyzer）可以替代，所以很少用。不过在没有可视化工具的机器上也是可用的。

常用指令

jmap -dump:format=b,file=heapDump 3331 + jhat heapDump：解析Java堆转储文件,并启动一个 web server

详细介绍

回到顶部

jstack

功能

生成当前时刻的线程快照。

常用指令

jstack 3331：查看线程情况

jstack -F 3331：正常输出不被响应时，使用该指令

jstack -l 3331：除堆栈外，显示关于锁的附件信息

Jstack -l PID » 123.txt 在发生死锁时可以用jstack -l pid来观察锁持有情况 »123.txt dump到指定文件

详细介绍

回到顶部

常见问题定位过程

频繁GC问题或内存溢出问题

一、使用jps查看线程ID

二、使用jstat -gc 3331 250 20 查看gc情况，一般比较关注PERM区的情况，查看GC的增长情况。

三、使用jstat -gccause：额外输出上次GC原因

四、使用jmap -dump:format=b,file=heapDump 3331生成堆转储文件

五、使用jhat或者可视化工具（Eclipse Memory Analyzer 、IBM HeapAnalyzer）分析堆情况。

六、结合代码解决内存溢出或泄露问题。

死锁问题

一、使用jps查看线程ID

二、使用jstack 3331：查看线程情况

回到顶部

结语

经常使用适当的虚拟机监控和分析工具可以加快我们分析数据、定位解决问题的速度，但也要知道，工具永远都是知识技能的一层包装，没有什么工具是包治百病的。

Java GC性能优化实战

GC优化是必要的吗？

或者更准确地说，GC优化对Java基础服务来说是必要的吗？答案是否定的，事实上GC优化对Java基础服务来说在有些场合是可以省去的，但前提是这些正在运行的Java系统，必须包含以下参数或行为： + 内存大小已经通过-Xms和-Xmx参数指定过 + 运行在server模式下（使用-server参数） + 系统中没有残留超时日志之类的错误日志

换句话说，如果你在运行时没有手动设置内存大小并且打印出了过多的超时日志，那你就需要对系统进行GC优化。

不过你需要时刻谨记一句话：GC tuning is the last task to be done.

现在来想一想GC优化的最根本原因，垃圾收集器的工作就是清除Java创建的对象，垃圾收集器需要清理的对象数量以及要执行的GC数量均取决于已创建的对象数量。因此，为了使你的系统在GC上表现良好，首先需要减少创建对象的数量。

俗话说“冰冻三尺非一日之寒”，我们在编码时要首先要把下面这些小细节做好，否则一些琐碎的不良代码累积起来将让GC的工作变得繁重而难于管理：

  • 使用StringBuilder或StringBuffer来代替String
  • 尽量少输出日志

尽管如此，仍然会有我们束手无策的情况。XML和JSON解析过程往往占用了最多的内存，即使我们已经尽可能地少用String、少输出日志，仍然会有大量的临时内存（大约10-100MB）被用来解析XML或JSON文件，但我们又很难弃用XML和JSON。在此，你只需要知道这一过程会占据大量内存即可。

如果在经过几次重复的优化后应用程序的内存用量情况有所改善，那么久可以启动GC优化了。

笔者总结了GC优化的两个目的： \1. 将进入老年代的对象数量降到最低 \2. 减少Full GC的执行时间

将进入老年代的对象数量降到最低

除了可以在JDK 7及更高版本中使用的G1收集器以外，其他分代GC都是由Oracle JVM提供的。关于分代GC，就是对象在Eden区被创建，随后被转移到Survivor区，在此之后剩余的对象会被转入老年代。也有一些对象由于占用内存过大，在Eden区被创建后会直接被传入老年代。老年代GC相对来说会比新生代GC更耗时，因此，减少进入老年代的对象数量可以显著降低Full GC的频率。你可能会以为减少进入老年代的对象数量意味着把它们留在新生代，事实正好相反，新生代内存的大小是可以调节的。

降低Full GC的时间

Full GC的执行时间比Minor GC要长很多，因此，如果在Full GC上花费过多的时间（超过1s），将可能出现超时错误。 + 如果通过减小老年代内存来减少Full GC时间，可能会引起OutOfMemoryError或者导致Full GC的频率升高。 + 另外，如果通过增加老年代内存来降低Full GC的频率，Full GC的时间可能因此增加。

因此，你需要把老年代的大小设置成一个“合适”的值。

影响GC性能的参数

不要幻想着“如果有人用他设置的GC参数获取了不错的性能，我们为什么不复制他的参数设置呢？”，因为对于不用的Web服务，它们创建的对象大小和生命周期都不相同。

举一个简单的例子，如果一个任务的执行条件是A，B，C，D和E，另一个完全相同的任务执行条件只有A和B，那么哪一个任务执行速度更快呢？作为常识来讲，答案很明显是后者。

Java GC参数的设置也是这个道理，设置好几个参数并不会提升GC执行的速度，反而会使它变得更慢。GC优化的基本原则是将不同的GC参数应用到两个及以上的服务器上然后比较它们的性能，然后将那些被证明可以提高性能或减少GC执行时间的参数应用于最终的工作服务器上。

下面这张表展示了与内存大小相关且会影响GC性能的GC参数

表1：GC优化需要考虑的JVM参数

类型 参数 描述
堆内存大小 -Xms 启动JVM时堆内存的大小
  -Xmx 堆内存最大限制
新生代空间大小 -XX:NewRatio 新生代和老年代的内存比
  -XX:NewSize 新生代内存大小
  -XX:SurvivorRatio Eden区和Survivor区的内存比

笔者在进行GC优化时最常用的参数是-Xms,-Xmx和-XX:NewRatio。-Xms和-Xmx参数通常是必须的，所以NewRatio的值将对GC性能产生重要的影响。

有些人可能会问如何设置永久代内存大小，你可以用-XX:PermSize和-XX:MaxPermSize参数来进行设置，但是要记住，只有当出现OutOfMemoryError错误时你才需要去设置永久代内存。

还有一个会影响GC性能的因素是垃圾收集器的类型,下表展示了关于GC类型的可选参数（基于JDK 6.0）：

表2：GC类型可选参数

GC类型 参数 备注
Serial GC -XX:+UseSerialGC  
Parallel GC -XX:+UseParallelGC-XX:ParallelGCThreads=value  
Parallel Compacting GC -XX:+UseParallelOldGC  
CMS GC -XX:+UseConcMarkSweepGC-XX:+UseParNewGC-XX:+CMSParallelRemarkEnabled-XX:CMSInitiatingOccupancyFraction=value-XX:+UseCMSInitiatingOccupancyOnly  
G1 -XX:+UnlockExperimentalVMOptions-XX:+UseG1GC 在JDK 6中这两个参数必须配合使用

除了G1收集器外，可以通过设置上表中每种类型第一行的参数来切换GC类型，最常见的非侵入式GC就是Serial GC，它针对客户端系统进行了特别的优化。

会影响GC性能的参数还有很多，但是上述的参数会带来最显著的效果，请切记，设置太多的参数并不一定会提升GC的性能。

GC优化的过程

GC优化的过程和大多数常见的提升性能的过程相似，下面是笔者使用的流程：

1.监控GC状态

你需要监控GC从而检查系统中运行的GC的各种状态

2.分析监控结果后决定是否需要优化GC

在检查GC状态后，你需要分析监控结构并决定是否需要进行GC优化。如果分析结果显示运行GC的时间只有0.1-0.3秒，那么就不需要把时间浪费在GC优化上，但如果运行GC的时间达到1-3秒，甚至大于10秒，那么GC优化将是很有必要的。

但是，如果你已经分配了大约10GB内存给Java，并且这些内存无法省下，那么就无法进行GC优化了。在进行GC优化之前，你需要考虑为什么你需要分配这么大的内存空间，如果你分配了1GB或2GB大小的内存并且出现了OutOfMemoryError，那你就应该执行堆转储（heap dump）来消除导致异常的原因。

注意：

堆转储（heap dump）是一个用来检查Java内存中的对象和数据的内存文件。该文件可以通过执行JDK中的jmap命令来创建。在创建文件的过程中，所有Java程序都将暂停，因此，不要再系统执行过程中创建该文件。

你可以在互联网上搜索heap dump的详细说明。

3.设置GC类型/内存大小

如果你决定要进行GC优化，那么你需要选择一个GC类型并且为它设置内存大小。此时如果你有多个服务器，请如上文提到的那样，在每台机器上设置不同的GC参数并分析它们的区别。

4.分析结果

在设置完GC参数后就可以开始收集数据，请在收集至少24小时后再进行结果分析。如果你足够幸运，你可能会找到系统的最佳GC参数。如若不然，你还需要分析输出日志并检查分配的内存，然后需要通过不断调整GC类型/内存大小来找到系统的最佳参数。

5.如果结果令人满意，将参数应用到所有服务器上并结束GC优化

如果GC优化的结果令人满意，就可以将参数应用到所有服务器上，并停止GC优化。

在下面的章节中，你将会看到上述每一步所做的具体工作。

监控GC状态并分析结果

在运行中的Web应用服务器（Web Application Server,WAS）上查看GC状态的最佳方式就是使用jstat命令。

下面的例子展示了某个还没有执行GC优化的JVM的状态（虽然它并不是运行服务器）。

$ jstat -gcutil 21719 1s
S0    S1    E    O    P    YGC    YGCT    FGC    FGCT GCT
48.66 0.00 48.10 49.70 77.45 3428 172.623 3 59.050 231.673
48.66 0.00 48.10 49.70 77.45 3428 172.623 3 59.050 231.673

我们先看一下YGC（从应用程序启动到采样时发生 Young GC 的次数）和YGCT（从应用程序启动到采样时 Young GC 所用的时间(秒)），计算YGCT/YGC会得出，平均每次新生代的GC耗时50ms，这是一个很小的数字，通过这个结果可以看出，我们大可不必关注新生代GC对GC性能的影响。

现在来看一下FGC（ 从应用程序启动到采样时发生 Full GC 的次数）和FGCT（从应用程序启动到采样时 Full GC 所用的时间(秒)），计算FGCT/FGC会得出，平均每次老年代的GC耗时19.68s。有可能是执行了三次Full GC，每次耗时19.68s，也有可能是有两次只花了1s,另一次花了58s。不管是哪一种情况，GC优化都是很有必要的。

使用jstat命令可以很容易地查看GC状态，但是分析GC的最佳方式是加上-verbosegc参数来生成日志。在之前的文章中笔者已经解释了如何分析这些日志。HPJMeter是笔者最喜欢的用于分析-verbosegc生成的日志的工具，它简单易用，使用HPJmeter可以很容易地查看GC执行时间以及GC发生频率。

此外，如果GC执行时间满足下列所有条件，就没有必要进行GC优化了： + Minor GC执行非常迅速（50ms以内） + Minor GC没有频繁执行（大约10s执行一次） + Full GC执行非常迅速（1s以内） + Full GC没有频繁执行（大约10min执行一次）

括号中的数字并不是绝对的，它们也随着服务的状态而变化。有些服务可能要求一次Full GC在0.9s以内，而有些则会放得更宽一些。因此，对于不同的服务，需要按照不同的标准考虑是否需要执行GC优化。

当检查GC状态时，不能只查看Minor GC和Full GC的时间，还必须要关注GC执行的次数。如果新生代空间太小，Minor GC将会非常频繁地执行（有时每秒会执行一次，甚至更多）。此外，传入老年代的对象数目会上升，从而导致Full GC的频率升高。因此，在执行jstat命令时，请使用-gccapacity参数来查看具体占用了多少空间。

设置GC类型/内存大小

设置GC类型

Oracle JVM有5种垃圾收集器，但是在JDK 7以前的版本中，你只能在Parallel GC, Parallel Compacting GC 和CMS GC之中选择，至于具体选择哪个，则没有具体的原则和规则。

既然这样的话，我们如何来选择GC呢？最好的方法是把三种都用上，但是有一点必须明确——CMS GC通常比其他并行（Parallel）GC都要快（这是因为CMS GC是并发的GC），如果确实如此，那只选择CMS GC就可以了，不过CMS GC也不总是更快，当出现concurrent mode failure时，CMS GC就会比并行GC更慢了。

Concurrent mode failure

现在让我们来深入地了解一下concurrent mode failure。

并行GC和CMS GC的最大区别是并行GC采用“标记-整理”(Mark-Compact)算法而CMS GC采用“标记-清除”(Mark-Sweep)算法,compact步骤就是通过移动内存来消除内存碎片，从而消除分配的内存之间的空白区域。

对于并行GC来说，无论何时执行Full GC，都会进行compact工作，这消耗了太多的时间。不过在执行完Full GC后，下次内存分配将会变得更快（因为直接顺序分配相邻的内存）。

相反，CMS GC没有compact的过程，因此CMS GC运行的速度更快。但是也是由于没有整理内存，在进行磁盘清理之前，内存中会有很多零碎的空白区域，这也导致没有足够的空间分配给大对象。例如，在老年代还有300MB可用空间，但是连一个10MB的对象都没有办法被顺序存储在老年代中，在这种情况下，会报出“concurrent mode failure”的warning，然后系统执行compact操作。但是CMS GC在这种情况下执行的compact操作耗时要比并行GC高很多，并且这还会导致另一个问题，关于“concurrent mode failure”的详细说明。

综上所述，你需要根据你的系统情况为其选择一个最适合的GC类型。

每个系统都有最适合它的GC类型等着你去寻找，如果你有6台服务器，我建议你每两个服务器设置相同的参数，然后加上-verbosegc参数再分析结果。

设置内存大小

下面展示了内存大小、GC运行次数和GC运行时间之间的关系：

大内存空间 + 减少了GC的次数 + 提高了GC的运行时间

小内存空间 + 增多了GC的次数 + 降低了GC的运行时间

关于如何设置内存的大小，没有一个标准答案，如果服务器资源充足并且Full GC能在1s内完成，把内存设为10GB也是可以的，但是大部分服务器并不处在这种状态中，当内存设为10GB时，Full GC会耗时10-30s,具体的时间自然与对象的大小有关。

既然如此，我们该如何设置内存大小呢？通常我推荐设为500MB，这不是说你要通过-Xms500m和-Xmx500m参数来设置WAS内存。根据GC优化之前的状态，如果Full GC后还剩余300MB的空间，那么把内存设为1GB是一个不错的选择（300MB（默认程序占用）+ 500MB（老年代最小空间）+200MB（空闲内存））。这意味着你需要为老年代设置至少500MB空间，因此如果你有三个运行服务器，可以把它们的内存分别设置为1GB，1.5GB，2GB，然后检查结果。

理论上来说，GC执行速度应该遵循1GB> 1.5GB> 2GB，1GB内存时GC执行速度最快。然而，理论上的1GB内存Full GC消耗1s、2GB内存Full GC消耗2 s在现实里是无法保证的，实际的运行时间还依赖于服务器的性能和对象大小。因此，最好的方法是创建尽可能多的测量数据并监控它们。

在设置内存空间大小时，你还需要设置一个参数：NewRatio。NewRatio的值是新生代和老年代空间大小的比例。如果XX:NewRatio=1，则新生代空间:老年代空间=1:1，如果堆内存为1GB，则新生代:老年代=500MB:500MB。如果NewRatio等于2，则新生代:老年代=1:2，因此，NewRatio的值设置得越大，则老年代空间越大，新生代空间越小。

你可能会认为把NewRatio设为1会是最好的选择，然而事实并非如此，根据笔者的经验，当NewRatio设为2或3时，整个GC的状态表现得更好。

完成GC优化最快地方法是什么？答案是比较性能测试的结果。为了给每台服务器设置不同的参数并监控它们，最好查看的是一或两天后的数据。当通过性能测试来进行GC优化时，你需要在不同的测试时保证它们有相同的负载和运行环境。然而，即使是专业的性能测试人员，想精确地控制负载也很困难，并且需要大量的时间准备。因此，更加方便容易的方式是直接设置参数来运行，然后等待运行的结果（即使这需要消耗更多的时间）。

分析GC优化的结果

在设置了GC参数和-verbosegc参数后，可以使用tail命令确保日志被正确地生成。如果参数设置得不正确或日志未生成，那你的时间就被白白浪费了。如果日志收集没有问题的话，在收集一或两天数据后再检查结果。最简单的方法是把日志从服务器移到你的本地PC上，然后用HPJMeter分析数据。

在分析结果时，请关注下列几点（这个优先级是笔者根据自己的经验拟定的，我认为选取GC参数时应考虑的最重要的因素是Full GC的运行时间。）： + 单次Full GC运行时间 + 单次Minor GC运行时间 + Full GC运行间隔 + Minor GC运行间隔 + 整个Full GC的时间 + 整个Minor GC的运行时间 + 整个GC的运行时间 + Full GC的执行次数 + Minor GC的执行次数

找到最佳的GC参数是件非常幸运的，然而在大多数时候，我们并不会如此幸运，在进行GC优化时一定要小心谨慎，因为当你试图一次完成所有的优化工作时，可能会出现OutOfMemoryError错误。

优化案例

到目前为止，我们一直在从理论上介绍GC优化，现在是时候将这些理论付诸实践了，我们将通过几个例子来更深入地理解GC优化。

示例1

下面这个例子是针对Service S的优化，对于最近刚开发出来的Service S，执行Full GC需要消耗过多的时间。

现在看一下执行jstat -gcutil的结果

S0 S1 E O P YGC YGCT FGC FGCT GCT
12.16 0.00 5.18 63.78 20.32 54 2.047 5 6.946 8.993

左边的Perm区的值对于最初的GC优化并不重要，而YGC参数的值更加对于这次优化更为重要。

平均执行一次Minor GC和Full GC消耗的时间如下表所示：

表3：Service S的Minor GC 和Full GC的平均执行时间

GC类型 GC执行次数 GC执行时间 平均值
Minor GC 54 2.047s 37ms
Full GC 5 6.946s 1.389s

37ms对于Minor GC来说还不赖，但1.389s对于Full GC来说意味着当GC发生在数据库Timeout设置为1s的系统中时，可能会频繁出现超时现象。

首先，你需要检查开始GC优化前内存的使用情况。使用jstat -gccapacity命令可以检查内存用量情况。在笔者的服务器上查看到的结果如下：

NGCMN NGCMX NGC S0C S1C EC OGCMN OGCMX OGC OC PGCMN PGCMX PGC PC YGC FGC
212992.0 212992.0 212992.0 21248.0 21248.0 170496.0 1884160.0 1884160.0 1884160.0 1884160.0 262144.0 262144.0 262144.0 262144.0 54 5

其中的关键值如下： + 新生代内存用量：212,992 KB + 老年代内存用量：1,884,160 KB

因此，除了永久代以外，被分配的内存空间加起来有2GB，并且新生代：老年代=1：9，为了得到比使用jstat更细致的结果，还需加上-verbosegc参数获取日志，并把三台服务器按照如下方式设置（除此以外没有使用任何其他参数）： + NewRatio=2 + NewRatio=3 + NewRatio=4

一天后我得到了系统的GC log，幸运的是，在设置完NewRatio后系统没有发生任何Full GC。

这是为什么呢？这是因为大部分对象在创建后很快就被回收了，所有这些对象没有被传入老年代，而是在新生代就被销毁回收了。

在这样的情况下，就没有必要去改变其他的参数值了，只要选择一个最合适的NewRatio值即可。那么，如何确定最佳的NewRatio值呢？为此，我们分析一下每种NewRatio值下Minor GC的平均响应时间。

在每种参数下Minor GC的平均响应时间如下： + NewRatio=2：45ms + NewRatio=3：34ms + NewRatio=4：30ms

我们可以根据GC时间的长短得出NewRatio=4是最佳的参数值（尽管NewRatio=4时新生代空间是最小的）。在设置完GC参数后，服务器没有发生Full GC。

为了说明这个问题，下面是服务执行一段时间后执行jstat –gcutil的结果:

S0 S1 E O P YGC YGCT FGC FGCT GCT
8.61 0.00 30.67 24.62 22.38 2424 30.219 0 0.000 30.219

你可能会认为是服务器接收的请求少才使得GC发生的频率较低，实际上，虽然Full GC没有执行过，但Minor GC被执行了2424次。

示例2

这是一个Service A的例子。我们通过公司内部的应用性能管理系统（APM）发现JVM暂停了相当长的时间（超过8秒），因此我们进行了GC优化。我们努力寻找JVM暂停的原因，后来发现是因为Full GC执行时间过长，因此我们决定进行GC优化。

在GC优化的开始阶段，我们加上了-verbosegc参数，结果如下图所示：

img

图1：进行GC优化之前STW的时间

上图是由HPJMeter生成的图片之一。横坐标表示JVM执行的时间，纵坐标表示每次GC的时间。CMS为绿点，表示Full GC的结果，而Parallel Scavenge为蓝点，表示Minor GC的结果。

之前我说过CMS GC是最快的GC，但是上面的结果显示在一些时候CMS耗时达到了15s。是什么导致了这一结果？请记住我之前说的：CMS在执行compact（整理）操作时会显著变慢。此外，服务的内存通过-Xms1g和=Xmx4g设置了，而分配的内存只有4GB。

因此笔者将GC类型从CMS GC改为了Parallel GC，把内存大小设为2GB，并把NewRatio设为3。在执行jstat -gcutil几小时后的结果如下：

S0 S1 E O P YGC YGCT FGC FGCT GCT
0.00 30.48 3.31 26.54 37.01 226 11.131 4 11.758 22.890

Full GC的时间缩短了，变成了每次3s，跟15s比有了显著提升。但是3s依然不够快，为此笔者创建了以下6种情况： + Case 1: -XX:+UseParallelGC -Xms1536m -Xmx1536m -XX:NewRatio=2 + Case 2: -XX:+UseParallelGC -Xms1536m -Xmx1536m -XX:NewRatio=3 + Case 3: -XX:+UseParallelGC -Xms1g -Xmx1g -XX:NewRatio=3 + Case 4: -XX:+UseParallelOldGC -Xms1536m -Xmx1536m -XX:NewRatio=2 + Case 5: -XX:+UseParallelOldGC -Xms1536m -Xmx1536m -XX:NewRatio=3 + Case 6: -XX:+UseParallelOldGC -Xms1g -Xmx1g -XX:NewRatio=3

上面哪一种情况最快？结果显示，内存空间越小，运行结果最少。下图展示了性能最好的Case 6的结果图，它的最慢响应时间只有1.7s，并且响应时间的平均值已经被控制到了1s以内。

img

图2：Case 6的持续时间图

基于上图的结果，按照Case 6调整了GC参数，但这却导致每晚都会发生OutOfMemoryError。很难解释发生异常的具体原因，简单地说，应该是批处理程序导致了内存泄漏，我们正在解决相关的问题。

如果只对GC日志做一些短时间的分析就将相关参数部署到所有服务器上来执行GC优化，这将是非常危险的。切记，只有当你同时仔细分析服务的执行情况和GC日志后，才能保证GC优化没有错误地执行。

在上文中，我们通过两个GC优化的例子来说明了GC优化是怎样执行的。正如上文中提到的，例子中设置的GC参数可以设置在相同的服务器之上，但前提是他们具有相同的CPU、操作系统、JDK版本并且运行着相同的服务。此外，不要把我使用的参数照搬到你的应用上，它们可能在你的机器上并不能起到同样良好的效果。

总结

笔者没有执行heap dump并分析内存的详细内容，而是通过自己的经验进行GC优化。精确地分析内存可以得到更好的优化效果，不过这种分析一般只适用于内存使用量相对固定的场景。如果服务严重过载并占有了大量的内存，则建议你根据之前的经验进行GC优化。

笔者已经在一些服务上设置了G1 GC参数并进行了性能测试，但还没有应用于正式的生产环境。G1 GC的速度快于任何其他的GC类型，但是你必须要升级到JDK 7。此外，暂时还无法保证它的稳定性，没有人知道运行时是否会出现致命的错误，因此G1 GC暂时还不适合投入应用。

等未来JDK 7真正稳定了（这并不是说它现在不稳定），并且WAS针对JDK 7进行优化后，G1 GC最终能按照预期的那样来工作，等到那一天我们可能就不再需要GC优化了。

GC调优工具实战

jps

用于显示当前用户下的所有java进程信息：

# jps [options] [hostid] 
# q:仅输出VM标识符, m: 输出main method的参数,l:输出完全的包名, v:输出jvm参数
[root@localhost ~]# jps -l
28729 sun.tools.jps.Jps
23789 cn.ms.test.DemoMain
23651 cn.ms.test.TestMain

jstat

用于监视虚拟机运行时状态信息（类装载、内存、垃圾收集、JIT编译等运行数据）：

-gc：垃圾回收统计（大小）

# 每隔2000ms输出<pid>进程的gc情况，一共输出2次
[root@localhost ~]# jstat -gc <pid> 2000 2
# 每隔2s输出<pid>进程的gc情况，每个3条记录就打印隐藏列标题
[root@localhost ~]# jstat -gc -t -h3 <pid> 2s
Timestamp        S0C    S1C    S0U    S1U    ... YGC     YGCT    FGC    FGCT     GCT   
         1021.6 1024.0 1024.0  0.0   1024.0  ...  1    0.012   0      0.000    0.012
         1023.7 1024.0 1024.0  0.0   1024.0  ...  1    0.012   0      0.000    0.012
         1025.7 1024.0 1024.0  0.0   1024.0  ...  1    0.012   0      0.000    0.012
Timestamp        S0C    S1C    S0U    S1U    ... YGC     YGCT    FGC    FGCT     GCT   
         1027.7 1024.0 1024.0  0.0   1024.0  ...  1    0.012   0      0.000    0.012
         1029.7 1024.0 1024.0  0.0   1024.0  ...  1    0.012   0      0.000    0.012
# 结果说明: C即Capacity 总容量，U即Used 已使用的容量
##########################
# S0C：年轻代中第一个survivor（幸存区）的容量 (kb)
# S1C：年轻代中第二个survivor（幸存区）的容量 (kb)
# S0U：年轻代中第一个survivor（幸存区）目前已使用空间 (kb)
# S1U：年轻代中第二个survivor（幸存区）目前已使用空间 (kb)
# EC：年轻代中Eden（伊甸园）的容量 (kb)
# EU：年轻代中Eden（伊甸园）目前已使用空间 (kb)
# OC：Old代的容量 (kb)
# OU：Old代目前已使用空间 (kb)
# PC：Perm(持久代)的容量 (kb)
# PU：Perm(持久代)目前已使用空间 (kb)
# YGC：从应用程序启动到采样时年轻代中gc次数
# YGCT：从应用程序启动到采样时年轻代中gc所用时间(s)
# FGC：从应用程序启动到采样时old代(全gc)gc次数
# FGCT：从应用程序启动到采样时old代(全gc)gc所用时间(s)
# GCT：从应用程序启动到采样时gc用的总时间(s)

-gcutil：垃圾回收统计（百分比）

[root@localhost bin]# jstat -gcutil <pid>
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
  0.00  99.80  16.21  26.18  93.34  90.74      9    0.056     2    0.045    0.102
# 结果说明
##########################
# S0：年轻代中第一个survivor（幸存区）已使用的占当前容量百分比
# S1：年轻代中第二个survivor（幸存区）已使用的占当前容量百分比
# E：年轻代中Eden（伊甸园）已使用的占当前容量百分比
# O：old代已使用的占当前容量百分比
# P：perm代已使用的占当前容量百分比
# YGC：从应用程序启动到采样时年轻代中gc次数
# YGCT：从应用程序启动到采样时年轻代中gc所用时间(s)
# FGC：从应用程序启动到采样时old代(全gc)gc次数
# FGCT：从应用程序启动到采样时old代(全gc)gc所用时间(s)
# GCT：从应用程序启动到采样时gc用的总时间(s)

-gccapacity：堆内存统计

[root@localhost ~]# jstat -gccapacity <pid>
 NGCMN    NGCMX     NGC     S0C   S1C       EC      OGCMN      OGCMX       OGC         OC      PGCMN    PGCMX     PGC       PC     YGC    FGC 
 84480.0 1349632.0 913408.0 54272.0 51200.0 502784.0   168448.0  2699264.0   168448.0   168448.0  21504.0  83968.0  51712.0  51712.0      9     0
# 结果说明
##########################
# NGCMN：年轻代(young)中初始化(最小)的大小 (kb)
# NGCMX：年轻代(young)的最大容量 (kb)
# NGC：年轻代(young)中当前的容量 (kb)
# S0C：年轻代中第一个survivor（幸存区）的容量 (kb)
# S1C：年轻代中第二个survivor（幸存区）的容量 (kb)
# EC：年轻代中Eden（伊甸园）的容量 (kb)
# OGCMN：old代中初始化(最小)的大小 (kb)
# OGCMX：old代的最大容量 (kb)
# OGC：old代当前新生成的容量 (kb)
# OC：Old代的容量 (kb)
# PGCMN：perm代中初始化(最小)的大小 (kb)
# PGCMX：perm代的最大容量 (kb)
# PGC：perm代当前新生成的容量 (kb)
# PC：Perm(持久代)的容量 (kb)
# YGC：从应用程序启动到采样时年轻代中gc次数
# GCT：从应用程序启动到采样时gc用的总时间(s)

-gccause：垃圾收集统计概述（同-gcutil），附加最近两次垃圾回收事件的原因

[root@localhost ~]# jstat -gccause <pid>
  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT    LGCC                 GCC       
  0.00  79.23  39.37  39.92  99.74      9    0.198     0    0.000    0.198 Allocation Failure   No GC
# 结果说明
##########################
# LGCC：最近垃圾回收的原因
# GCC：当前垃圾回收的原因

jstack

jstack(Java Stack Trace)主要用于打印线程的堆栈信息，是JDK自带的很强大的线程分析工具，可以帮助我们排查程序运行时的线程状态、死锁状态等。

# dump出进程<pid>的线程堆栈快照至/data/1.log文件中
jstack -l <pid> >/data/1.log

# 参数说明：
# -F：如果正常执行jstack命令没有响应（比如进程hung住了），可以加上此参数强制执行thread dump
# -m：除了打印Java的方法调用栈之外，还会输出native方法的栈帧
# -l：打印与锁有关的附加信息。使用此参数会导致JVM停止时间变长，在生产环境需慎用

jstack dump文件中值得关注的线程状态有：

  • 死锁（Deadlock） —— 重点关注
  • 执行中（Runnable）
  • 等待资源（Waiting on condition） —— 重点关注
    • 等待某个资源或条件发生来唤醒自己。具体需结合jstacktrace来分析，如线程正在sleep，网络读写繁忙而等待
    • 如果大量线程在“waiting on condition”，并且在等待网络资源，可能是网络瓶颈的征兆
  • 等待获取监视器（Waiting on monitor entry） —— 重点关注
    • 如果大量线程在“waiting for monitor entry”，可能是一个全局锁阻塞住了大量线程
  • 暂停（Suspended）
  • 对象等待中（Object.wait() 或 TIMED_WAITING）
  • 阻塞（Blocked） —— 重点关注
  • 停止（Parked）

注意：如果某个相同的call stack经常出现， 我们有80%的以上的理由确定这个代码存在性能问题（读网络的部分除外）。

场景一：分析BLOCKED问题

"RMI TCP Connection(267865)-172.16.5.25" daemon prio=10 tid=0x00007fd508371000 nid=0x55ae waiting for monitor entry [0x00007fd4f8684000]
   java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.log4j.Category.callAppenders(Category.java:201)
- waiting to lock <0x00000000acf4d0c0> (a org.apache.log4j.Logger)
at org.apache.log4j.Category.forcedLog(Category.java:388)
at org.apache.log4j.Category.log(Category.java:853)
at org.apache.commons.logging.impl.Log4JLogger.warn(Log4JLogger.java:234)
at com.tuan.core.common.lang.cache.remote.SpyMemcachedClient.get(SpyMemcachedClient.java:110)
  • 线程状态是 Blocked，阻塞状态。说明线程等待资源超时
  • “ waiting to lock <0x00000000acf4d0c0>”指，线程在等待给这个 0x00000000acf4d0c0 地址上锁（英文可描述为：trying to obtain 0x00000000acf4d0c0 lock）
  • 在 dump 日志里查找字符串 0x00000000acf4d0c0，发现有大量线程都在等待给这个地址上锁。如果能在日志里找到谁获得了这个锁（如locked < 0x00000000acf4d0c0 >），就可以顺藤摸瓜了
  • “waiting for monitor entry”说明此线程通过 synchronized(obj) {……} 申请进入了临界区，从而进入了下图1中的“Entry Set”队列，但该 obj 对应的 monitor 被其他线程拥有，所以本线程在 Entry Set 队列中等待
  • 第一行里，”RMI TCP Connection(267865)-172.16.5.25”是 Thread Name 。tid指Java Thread id。nid指native线程的id。prio是线程优先级。[0x00007fd4f8684000]是线程栈起始地址。

场景二：分析CPU过高问题

1.top命令找出最高占用的进程（Shift+P）

2.查看高负载进程下的高负载线程（top -Hp 或ps -mp -o THREAD,tid,time）

3.找出最高占用的线程并记录thread_id，把线程号进行换算成16进制编号（printf “%X\n” thread_id）

4.（可选）执行查看高负载的线程名称（jstack 16143 grep 3fb6）

5.导出进程的堆栈日志，找到3fb6 这个线程号（jstack 16143 >/home/16143.log）

6.根据找到的堆栈信息关联到代码进行定位分析即可

jmap

jmap(Java Memory Map)主要用于打印内存映射。常用命令：

jmap -dump:live,format=b,file=xxx.hprof <pid>

查看JVM堆栈的使用情况

[root@localhost ~]# jmap -heap 7243
Attaching to process ID 27900, please wait...
Debugger attached successfully.
Client compiler detected.
JVM version is 20.45-b01
using thread-local object allocation.
Mark Sweep Compact GC
Heap Configuration: #堆内存初始化配置
   MinHeapFreeRatio = 40     #-XX:MinHeapFreeRatio设置JVM堆最小空闲比率  
   MaxHeapFreeRatio = 70   #-XX:MaxHeapFreeRatio设置JVM堆最大空闲比率  
   MaxHeapSize = 100663296 (96.0MB)   #-XX:MaxHeapSize=设置JVM堆的最大大小
   NewSize = 1048576 (1.0MB)     #-XX:NewSize=设置JVM堆的‘新生代’的默认大小
   MaxNewSize = 4294901760 (4095.9375MB) #-XX:MaxNewSize=设置JVM堆的‘新生代’的最大大小
   OldSize = 4194304 (4.0MB)  #-XX:OldSize=设置JVM堆的‘老生代’的大小
   NewRatio = 2    #-XX:NewRatio=:‘新生代’和‘老生代’的大小比率
   SurvivorRatio = 8  #-XX:SurvivorRatio=设置年轻代中Eden区与Survivor区的大小比值
   PermSize = 12582912 (12.0MB) #-XX:PermSize=<value>:设置JVM堆的‘持久代’的初始大小  
   MaxPermSize = 67108864 (64.0MB) #-XX:MaxPermSize=<value>:设置JVM堆的‘持久代’的最大大小  
Heap Usage:
New Generation (Eden + 1 Survivor Space): #新生代区内存分布，包含伊甸园区+1个Survivor区
   capacity = 30212096 (28.8125MB)
   used = 27103784 (25.848182678222656MB)
   free = 3108312 (2.9643173217773438MB)
   89.71169693092462% used
Eden Space: #Eden区内存分布
   capacity = 26869760 (25.625MB)
   used = 26869760 (25.625MB)
   free = 0 (0.0MB)
   100.0% used
From Space: #其中一个Survivor区的内存分布
   capacity = 3342336 (3.1875MB)
   used = 234024 (0.22318267822265625MB)
   free = 3108312 (2.9643173217773438MB)
   7.001809512867647% used
To Space: #另一个Survivor区的内存分布
   capacity = 3342336 (3.1875MB)
   used = 0 (0.0MB)
   free = 3342336 (3.1875MB)
   0.0% used
PS Old Generation: #当前的Old区内存分布
   capacity = 67108864 (64.0MB)
   used = 67108816 (63.99995422363281MB)
   free = 48 (4.57763671875E-5MB)
   99.99992847442627% used
PS Perm Generation: #当前的 “持久代” 内存分布
   capacity = 14417920 (13.75MB)
   used = 14339216 (13.674942016601562MB)
   free = 78704 (0.0750579833984375MB)
   99.45412375710227% used

新生代内存回收就是采用空间换时间方式；如果from区使用率一直是100% 说明程序创建大量的短生命周期的实例，使用jstat统计jvm在内存回收中发生的频率耗时以及是否有full gc，使用这个数据来评估一内存配置参数、gc参数是否合理。

统计一【jmap -histo】：统计所有类的实例数量和所占用的内存容量

[root@localhost ~]# jmap -histo 7243
 num     #instances         #bytes  class name
----------------------------------------------
   1:          8969       19781168  [B
   2:          1835        2296720  [I
   3:         19735        2050688  [C
   4:          3448         385608  java.lang.Class
   5:          3829         371456  [Ljava.lang.Object;
   6:         14634         351216  java.lang.String
   7:          6695         214240  java.util.concurrent.ConcurrentHashMap$Node
   8:          6257         100112  java.lang.Object
   9:          2155          68960  java.util.HashMap$Node
  10:           723          63624  java.lang.reflect.Method
  11:            49          56368  [Ljava.util.concurrent.ConcurrentHashMap$Node;
  12:           830          46480  java.util.zip.ZipFile$ZipFileInputStream
  13:          1146          45840  java.lang.ref.Finalizer
  ......

统计二【jmap -histo】：查看对象数最多的对象，并过滤Map关键词，然后按降序排序输出

[root@localhost ~]# jmap -histo 7243 |grep Map|sort -k 2 -g -r|less
Total         96237       26875560
   7:          6695         214240  java.util.concurrent.ConcurrentHashMap$Node
   9:          2155          68960  java.util.HashMap$Node
  18:           563          27024  java.util.HashMap
  21:           505          20200  java.util.LinkedHashMap$Entry
  16:           337          34880  [Ljava.util.HashMap$Node;
  27:           336          16128  gnu.trove.THashMap
  56:           163           6520  java.util.WeakHashMap$Entry
  60:           127           6096  java.util.WeakHashMap
  38:           127          10144  [Ljava.util.WeakHashMap$Entry;
  53:           126           7056  java.util.LinkedHashMap
......

统计三【jmap -histo】：统计实例数量最多的前10个类

[root@localhost ~]# jmap -histo 7243 | sort -n -r -k 2 | head -10
 num     #instances         #bytes  class name
----------------------------------------------
Total         96237       26875560
   3:         19735        2050688  [C
   6:         14634         351216  java.lang.String
   1:          8969       19781168  [B
   7:          6695         214240  java.util.concurrent.ConcurrentHashMap$Node
   8:          6257         100112  java.lang.Object
   5:          3829         371456  [Ljava.lang.Object;
   4:          3448         385608  java.lang.Class
   9:          2155          68960  java.util.HashMap$Node
   2:          1835        2296720  [I

统计四【jmap -histo】：统计合计容量最多的前10个类

[root@localhost ~]# jmap -histo 7243 | sort -n -r -k 3 | head -10
 num     #instances         #bytes  class name
----------------------------------------------
Total         96237       26875560
   1:          8969       19781168  [B
   2:          1835        2296720  [I
   3:         19735        2050688  [C
   4:          3448         385608  java.lang.Class
   5:          3829         371456  [Ljava.lang.Object;
   6:         14634         351216  java.lang.String
   7:          6695         214240  java.util.concurrent.ConcurrentHashMap$Node
   8:          6257         100112  java.lang.Object
   9:          2155          68960  java.util.HashMap$Node

dump注意事项

  • 在应用快要发生FGC的时候把堆数据导出来

    ​ 老年代或新生代used接近100%时，就表示即将发生GC，也可以再JVM参数中指定触发GC的阈值。

    • 查看快要发生FGC使用命令：jmap -heap < pid >
    • 数据导出：jmap -dump:format=b,file=heap.bin < pid >
  • 通过命令查看大对象：jmap -histo < pid > less

使用总结

  • 如果程序内存不足或者频繁GC，很有可能存在内存泄露情况，这时候就要借助Java堆Dump查看对象的情况
  • 要制作堆Dump可以直接使用jvm自带的jmap命令
  • 可以先使用jmap -heap命令查看堆的使用情况，看一下各个堆空间的占用情况
  • 使用jmap -histo:[live]查看堆内存中的对象的情况。如果有大量对象在持续被引用，并没有被释放掉，那就产生了内存泄露，就要结合代码，把不用的对象释放掉
  • 也可以使用 jmap -dump:format=b,file=<fileName>命令将堆信息保存到一个文件中，再借助jhat命令查看详细内容
  • 在内存出现泄露、溢出或者其它前提条件下，建议多dump几次内存，把内存文件进行编号归档，便于后续内存整理分析
  • 在用cms gc的情况下，执行jmap -heap有些时候会导致进程变T，因此强烈建议别执行这个命令，如果想获取内存目前每个区域的使用状况，可通过jstat -gc或jstat -gccapacity来拿到

jhat

jhat（JVM Heap Analysis Tool）命令是与jmap搭配使用，用来分析jmap生成的dump，jhat内置了一个微型的HTTP/HTML服务器，生成dump的分析结果后，可以在浏览器中查看。在此要注意，一般不会直接在服务器上进行分析，因为jhat是一个耗时并且耗费硬件资源的过程，一般把服务器生成的dump文件复制到本地或其他机器上进行分析。

# 解析Java堆转储文件,并启动一个 web server
jhat heapDump.dump

jconsole

jconsole(Java Monitoring and Management Console)是一个Java GUI监视工具，可以以图表化的形式显示各种数据，并可通过远程连接监视远程的服务器VM。用java写的GUI程序，用来监控VM，并可监控远程的VM，非常易用，而且功能非常强。命令行里打jconsole，选则进程就可以了。

第一步：在远程机的tomcat的catalina.sh中加入配置：

JAVA_OPTS="$JAVA_OPTS -Djava.rmi.server.hostname=192.168.202.121 -Dcom.sun.management.jmxremote"
JAVA_OPTS="$JAVA_OPTS -Dcom.sun.management.jmxremote.port=12345"
JAVA_OPTS="$JAVA_OPTS -Dcom.sun.management.jmxremote.authenticate=true"
JAVA_OPTS="$JAVA_OPTS -Dcom.sun.management.jmxremote.ssl=false"
JAVA_OPTS="$JAVA_OPTS -Dcom.sun.management.jmxremote.pwd.file=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.101-3.b13.el7_2.x86_64/jre/lib/management/jmxremote.password"

第二步：配置权限文件

[root@localhost bin]# cd /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.101-3.b13.el7_2.x86_64/jre/lib/management/
[root@localhost management]# cp jmxremote.password.template jmxremote.password
[root@localhost management]# vi jmxremote.password

monitorRole QED controlRole chenqimiao

第三步：配置权限文件为600

[root@localhost management]# chmod 600 jmxremote.password jmxremote.access

这样基本配置就结束了，下面说两个坑，第一个就是防火墙的问题，要开放指定端口的防火墙，我这里配置的是12345端口，第二个是hostname的问题：

jconsole-ip2

请将127.0.0.1修改为本地真实的IP,我的服务器IP是192.168.202.121：

jconsole-ip

第四步：查看JConsole

JConsole-新建连接

JConsole-Console

jvisualvm

jvisualvm(JVM Monitoring/Troubleshooting/Profiling Tool)同jconsole都是一个基于图形化界面的、可以查看本地及远程的JAVA GUI监控工具，Jvisualvm同jconsole的使用方式一样，直接在命令行打入Jvisualvm即可启动，不过Jvisualvm相比，界面更美观一些，数据更实时。 jvisualvm的使用VisualVM进行远程连接的配置和JConsole是一摸一样的，最终效果图如下

jvisualvm

Visual GC(监控垃圾回收器)

Java VisualVM默认没有安装Visual GC插件，需要手动安装，JDK的安装目录的bin目露下双击 jvisualvm.sh，即可打开Java VisualVM，点击菜单栏： 工具->插件 安装Visual GC，最终效果如下图所示：

Visual-GC

大dump文件

从服务器dump堆内存后文件比较大（5.5G左右），加载文件、查看实例对象都很慢，还提示配置xmx大小。表明给VisualVM分配的堆内存不够，找到$JAVA_HOME/lib/visualvm}/etc/visualvm.conf这个文件，修改：

default_options="-J-Xms24m -J-Xmx192m"

再重启VisualVM就行了。

jmc

jmc（Java Mission Control）是JDK自带的一个图形界面监控工具，监控信息非常全面。JMC打开性能日志后，主要包括一般信息、内存、代码、线程、I/O、系统、事件 功能。

jmc-main

JMC的最主要的特征就是JFR（Java Flight Recorder），是基于JAVA的飞行记录器，JFR的数据是一些列JVM事件的历史纪录，可以用来诊断JVM的性能和操作，收集后的数据可以使用JMC来分析。

启动JFR

在商业版本上面，JFR默认是关闭的，可以通过在启动时增加参数 -XX:+UnlockCommercialFeatures -XX:+FlightRecorder 来启动应用。启动之后，也只是开启了JFR特性，但是还没有开始进行事件记录。这就要通过GUI和命令行了。

  • 通过Java Mission Control启动JFR

    打开Java Mission Control点击对应的JVM启动即可，事件记录有两种模式（如果选择第2种模式，那么JVM会使用一个循环使用的缓存来存放事件数据）：

    • 记录固定一段时间的事件（比如：1分钟）
    • 持续进行记录

  • 通过命令行启动JFR

    通过在启动的时候，增加参数：-XX:+FlightRecorderOptions=string 来启动真正地事件记录，这里的 string 可以是以下值（下列参数都可以使用jcmd命令，在JVM运行的时候进行动态调整，参考地址）：

    • name=name：标识recording的名字（一个进程可以有多个recording存在，它们使用名字来进行区分）
    • defaultrecording=<ture|false>：是否启动recording，默认是false，我们要分析，必须要设置为true
    • setting=paths：包含JFR配置的文件名字
    • delay=time：启动之后，经过多长时间（比如：30s，1h）开始进行recording
    • duration=time：做多长时间的recording
    • filename=path：recordding记录到那个文件里面
    • compress=<ture|false>：是否对recording进行压缩（gzip）,默认为false
    • maxage=time：在循环使用的缓存中，事件数据保存的最大时长
    • maxsize=size：事件数据缓存的最大大小（比如：1024k，1M）

常用JFR命令

  • 启动recording

    命令格式：jcmd process_id JFR.start [options_list]，其中options_list就是上述的参数值。

  • dump出循环缓存中的数据

    命令格式：jcmd process_id JFR.dump [options_list]，其中options_list参数的可选值如下：

    • name=name：recording的名字
    • recording=n：JFR recording的数字（一个标识recording的随机数）
    • filename=path：dump文件的保存路径

  • 查看进程中所有recording

    命令格式： jcmd process_id JFR.check [verbose]，不同recording使用名字进行区分，同时JVM还为它分配一个随机数。

  • 停止recording

    命令格式： jcmd process_id JFR.stop [options_list]，其中options_list参数的可选值如下：

    • name=name：要停止的recording名字
    • recording=n：要停止的recording的标识数字
    • discard=boolean：如果为true，数据被丢弃，而不是写入下面指定的文件当中
    • filename=path：写入数据的文件名称

命令启动JFR案例

  • 第一步：创建一个包含了你自己配置的JFR模板文件（template.jfc）。运行jmc, 然后Window->Flight Recording Template Manage菜单。准备好档案后，就可以导出文件，并移动到要排查问题的环境中

    jmc-jfc

  • 第二步：由于JFR需要JDK的商业证书，这一步需要解锁jdk的商业特性

    [root@localhost bin]# jcmd 12234 VM.unlock_commercial_features
12234: Commercial Features already unlocked.

  • 第三步：最后你就可以启动JFR，命令格式如下：

    jcmd <PID> JFR.start name=test duration=60s [settings=template.jfc] filename=output.jfr

    ​ 上述命令立即启动JFR并开始使用 template.jfc（在 $JAVA_HOME/jre/lib/jfr 下有 default.jfc 和 profile.jfc 模板）的配置收集 60s 的JVM信息，输出到 output.jfr 中。一旦记录完成之后，就可以复制.jfr文件到你的工作环境使用jmc GUI来分析。它几乎包含了排查jvm问题需要的所有信息，包括堆dump时的异常信息。使用案例如下：

    [root@localhost bin]# jcmd 12234 JFR.start name=test duration=60s filename=output.jfr
12234: Started recording 6. The result will be written to: /root/zookeeper-3.4.12/bin/output.jfr
[root@localhost bin]# ls -l
-rw-r--r-- 1 root root 298585 6月  29 11:09 output.jfr

JFR（Java Flight Recorder）

  • Java Mission Control的最主要的特征就是Java Flight Recorder。正如它的名字所示，JFR的数据是一些列JVM事件的历史纪录，可以用来诊断JVM的性能和操作
  • JFR的基本操作就是开启哪些事件（比如：线程由于等待锁而阻塞的事件）。当开启的事件发生了，事件相关的数据会记录到内存或磁盘文件上。记录事件数据的缓存是循环使用的，只有最近发生的事件才能够从缓存中找到，之前的都因为缓存的限制被删除了。Java Mission Control能够对这些事件在界面上进行展示（从JVM的内存中读取或从事件数据文件中读取），我们可以通过这些事件来对JVM的性能进行诊断
  • 事件的类型、缓存的大小、事件数据的存储方式等等都是通过JVM参数、Java Mission Control的GUI界面、jcmd命令来控制的。JFR默认是编译进程序的，因为它的开销很小，一般来说对应用的影响小于1%。不过，如果我们增加了事件的数目、修改了记录事件的阈值，都有可能增加JFR的开销

JFR概况

​ 下面对GlassFish web服务器进行JFR记录的例子，在这个服务器上面运行着在第2章介绍的股票servlet。Java Mission Control加载完JFR获取的事件之后，大概是下面这个样子：

jfr-main

我们可以看到，通过上图可以看到：CPU使用率，Heap使用率，JVM信息，System Properties，JFR的记录情况等等。

JFR内存视图

Java Mission Control 可以看到非常多的信息，下图只显示了一个标签的内容。下图显示了JVM 的内存波动非常频繁，因为新生代经常被清除（有意思的是，head的大小并没有增长）。下面左边的面板显示了最近一段时间的垃圾回收情况，包括：GC的时长和垃圾回收的类型。如果我们点击一个事件，右边的面板会展示这个事件的具体情况，包括：垃圾垃圾回收的各个阶段及其统计信息。从面板的标签可以看到，还有很多其它信息，比如：有多少对象被清除了，花了多长时间；GC算法的配置；分配的对象信息等等。在第5章和第6章中，我们会详细介绍。

jfr-memory

JFR 代码视图

这张图也有很多tab，可以看到各个包的使用频率和类的使用情况、异常、编译、代码缓存、类加载情况等等：

jfr-code

JFR事件视图

下图显示了事件的概述视图：

jfr-event

EclipseMAT

虽然Java虚拟机可以帮我们对内存进行回收，但是其回收的是Java虚拟机不再引用的对象。很多时候我们使用系统的IO流、Cursor、Receiver如果不及时释放，就会导致内存泄漏（OOM）。但是，很多时候内存泄漏的现象不是很明显，比如内部类、Handler相关的使用导致的内存泄漏，或者你使用了第三方library的一些引用，比较消耗资源，但又不是像系统资源那样会引起你足够的注意去手动释放它们。以下通过内存泄漏分析、集合使用率、Hash性能分析和OQL快读定位空集合来使用MAT。

GC Roots

JAVA虚拟机通过可达性（Reachability)来判断对象是否存活，基本思想：以”GC Roots”的对象作为起始点向下搜索，搜索形成的路径称为引用链，当一个对象到GC Roots没有任何引用链相连（即不可达的），则该对象被判定为可以被回收的对象，反之不能被回收。GC Roots可以是以下任意对象

  • 一个在current thread（当前线程）的call stack（调用栈）上的对象（如方法参数和局部变量）
  • 线程自身或者system class loader（系统类加载器）加载的类
  • native code（本地代码）保留的活动对象

内存泄漏

当对象无用了，但仍然可达（未释放），垃圾回收器无法回收。

Java四种引用类型

  • Strong References（强引用）

    普通的java引用，我们通常new的对象就是：StringBuffer buffer = new StringBuffer(); 如果一个对象通过一串强引用链可达，那么它就不会被垃圾回收。你肯定不希望自己正在使用的引用被垃圾回收器回收吧。但对于集合中的对象，应在不使用的时候移除掉，否则会占用更多的内存，导致内存泄漏。

  • Soft Reference（软引用）

    当对象是Soft Reference可达时，gc会向系统申请更多内存，而不是直接回收它，当内存不足的时候才回收它。因此Soft Reference适合用于构建一些缓存系统，比如图片缓存。

  • Weak Reference（弱引用）

    WeakReference不会强制对象保存在内存中。它拥有比较短暂的生命周期，允许你使用垃圾回收器的能力去权衡一个对象的可达性。在垃圾回收器扫描它所管辖的内存区域过程中，一旦gc发现对象是Weak Reference可达，就会把它放到 Reference Queue 中，等下次gc时回收它。

    系统为我们提供了WeakHashMap，和HashMap类似，只是其key使用了weak reference。如果WeakHashMap的某个key被垃圾回收器回收，那么entity也会自动被remove。由于WeakReference被GC回收的可能性较大，因此，在使用它之前，你需要通过weakObj.get()去判断目的对象引用是否已经被回收。一旦WeakReference.get()返回null，它指向的对象就会被垃圾回收，那么WeakReference对象就没有用了，意味着你应该进行一些清理。比如在WeakHashMap中要把回收过的key从Map中删除掉，避免无用的的weakReference不断增长。

    ReferenceQueue可以让你很容易地跟踪dead references。WeakReference类的构造函数有一个ReferenceQueue参数，当指向的对象被垃圾回收时，会把WeakReference对象放到ReferenceQueue中。这样，遍历ReferenceQueue可以得到所有回收过的WeakReference。

  • Phantom Reference（虚引用）

    其余Soft/Weak Reference区别较大是它的get()方法总是返回null。这意味着你只能用Phantom Reference本身，而得不到它指向的对象。当Weak Reference指向的对象变得弱可达(weakly reachable）时会立即被放到ReferenceQueue中，这在finalization、garbage collection之前发生。理论上，你可以在finalize()方法中使对象“复活”（使一个强引用指向它就行了，gc不会回收它）。但没法复活PhantomReference指向的对象。而PhantomReference是在garbage collection之后被放到ReferenceQueue中的，没法复活。

MAT视图与概念

  • Shallow Heap

    Shallow Size就是对象本身占用内存的大小，不包含其引用的对象内存，实际分析中作用不大。 常规对象（非数组）的Shallow Size由其成员变量的数量和类型决定。数组的Shallow Size有数组元素的类型（对象类型、基本类型）和数组长度决定。案例如下：

public class String {
    public final class String {8 Bytes header
    private char value[]; 4 Bytes
    private int offset; 4 Bytes
    private int count; 4 Bytes
    private int hash = 0; 4 Bytes
	// ......
}
// "Shallow size“ of a String ==24 Bytes12345678

Java的对象成员都是些引用。真正的内存都在堆上，看起来是一堆原生的byte[]、char[]、int[]，对象本身的内存都很小。所以我们可以看到以Shallow Heap进行排序的Histogram图中，排在第一位第二位的是byte和char。

  • Retained Heap

    Retained Heap值的计算方式是将Retained Set中的所有对象大小叠加。或者说，由于X被释放，导致其它所有被释放对象（包括被递归释放的）所占的Heap大小。当X被回收时哪些将被GC回收的对象集合。比如:

    一个ArrayList持有100000个对象，每一个占用16 bytes，移除这些ArrayList可以释放16×100000+X，X代表ArrayList的Shallow大小。相对于Shallow Heap，Retained Heap可以更精确的反映一个对象实际占用的大小（因为如果该对象释放，Retained Heap都可以被释放）。

  • Histogram

    可列出每一个类的实例数。支持正则表达式查找，也可以计算出该类所有对象的Retained Size。

mat-histogram

  • Dominator Tree

    对象之间dominator关系树。如果从GC Root到达Y的的所有path都经过X，那么我们称X dominates Y，或者X是Y的Dominator Dominator Tree由系统中复杂的对象图计算而来。从MAT的dominator tree中可以看到占用内存最大的对象以及每个对象的dominator。 我们也可以右键选择Immediate Dominator”来查看某个对象的dominator。

mat-dominator-tree

  • Path to GC Roots

    ​ 查看一个对象到RC Roots的引用链通常在排查内存泄漏的时候，我们会选择exclude all phantom/weak/soft etc.references, 意思是查看排除虚引用/弱引用/软引用等的引用链，因为被虚引用/弱引用/软引用的对象可以直接被GC给回收，我们要看的就是某个对象否还存在Strong 引用链（在导出HeapDump之前要手动出发GC来保证），如果有，则说明存在内存泄漏，然后再去排查具体引用。

    mat-path-to-gc-roots

    查看当前Object所有引用,被引用的对象：

    • List objects with （以Dominator Tree的方式查看）
      • incoming references 引用到该对象的对象
      • outcoming references 被该对象引用的对象
    • Show objects by class （以class的方式查看）
      • incoming references 引用到该对象的对象
      • outcoming references 被该对象引用的对象

  • OQL(Object Query Language)

类似SQL查询语言：Classes：Table、Objects：Rows、Fileds：Cols

select * from com.example.mat.Listener
# 查找size＝0并且未使用过的ArrayList
select * from java.util.ArrayList where size=0 and modCount=01
# 查找所有的Activity 
select * from instanceof android.app.Activity
  • 内存快照对比

方式一：Compare To Another Heap Dump（直接进行比较）

mat-compare-to-another-heap-dump-1

mat-compare-to-another-heap-dump-2

mat-compare-to-another-heap-dump-3

方式二：Compare Baseket（更全面，可以直接给出百分比）

mat-compare-baseket-1

mat-compare-baseket-2

mat-compare-baseket-3

mat-compare-baseket-4

MAT内存分析实战

  • 实战一：内存泄漏分析

    查找导致内存泄漏的类。既然环境已经搭好，heap dump也成功倒入，接下来就去分析问题。

    • 查找目标类 如果在开发过程中，你的目标很明确，比如就是查找自己负责的服务，那么通过包名或者Class筛选，OQL搜索都可以快速定位到。点击OQL图标，在窗口输入，并按Ctrl + F5或者!按钮执行：

      select * from instanceof android.app.Activity

    • Paths to GC Roots：exclude all phantom/weak/soft etc.references

      查看一个对象到RC Roots是否存在引用链。要将虚引用/弱引用/软引用等排除，因为被虚引用/弱引用/软引用的对象可以直接被GC给回收

    • 分析具体的引用为何没有被释放，并进行修复

小技巧：

  • 当目的不明确时，可以直接定位到RetainedHeap最大的Object，Select incoming references，查看引用链，定位到可疑的对象然后Path to GC Roots进行引用链分析
  • 如果大对象筛选看不出区别，可以试试按照class分组，再寻找可疑对象进行GC引用链分析
  • 直接按照包名直接查看GC引用链，可以一次性筛选多个类，但是如下图所示，选项是 Merge Shortest Path to GCRoots，这个选项具体不是很明白，不过也能筛选出存在GC引用链的类，这种方式的准确性还待验证

mat-实践一

所以有时候进行MAT分析还是需要一些经验，能够帮你更快更准确的定位。

  • 实战二：集合使用率分析

    集合在开发中会经常使用到，如何选择合适的数据结构的集合，初始容量是多少（太小，可能导致频繁扩容），太大，又会开销跟多内存。当这些问题不是很明确时或者想查看集合的使用情况时，可以通过MAT来进行分析。

    • 筛选目标对象

      mat-实践二-1

    • Show Retained Set（查找当X被回收时那些将被GC回收的对象集合）

      mat-实践二-2

    • 筛选指定的Object（Hash Map，ArrayList）并按照大小进行分组

      mat-实践二-3

    • 查看指定类的Immediate dominators

      mat-实践二-4

Collections fill ratio

这种方式只能查看那些具有预分配内存能力的集合，比如HashMap，ArrayList。计算方式：”size / capacity”

mat-实践二-5

mat-实践二-6

  • 实战三：Hash相关性能分析

    当Hash集合中过多的对象返回相同Hash值的时候，会严重影响性能（Hash算法原理自行搜索），这里来查找导致Hash集合的碰撞率较高的罪魁祸首。

    • Map Collision Ratio

      检测每一个HashMap或者HashTable实例并按照碰撞率排序：碰撞率 = 碰撞的实体/Hash表中所有实体

      mat-实践三-1

    • 查看Immediate dominators

      mat-实践三-2

      mat-实践三-3

    • 通过HashEntries查看key value

      mat-实践三-4

    • Array等其它集合分析方法类似

  • 实战四：通过OQL快速定位未使用的集合

    • 通过OQL查询empty并且未修改过的集合：

      select * from java.util.ArrayList where size=0 and modCount=01
select * from java.util.HashMap where size=0 and modCount=0
select * from java.util.Hashtable where count=0 and modCount=012

      mat-实践四-1

    • Immediate dominators(查看引用者)

      mat-实践四-2

    • 计算空集合的Retained Size值，查看浪费了多少内存

      mat-实践四-3

🔥火焰图

火焰图是用来分析程序运行瓶颈的工具。火焰图也可以用来分析 Java 应用。

环境安装

确认你的机器已经安装了git、jdk、perl、c++编译器。

安装Perl

wget http://www.cpan.org/src/5.0/perl-5.26.1.tar.gz
tar zxvf perl-5.26.1.tar.gz
cd perl-5.26.1
./Configure -de
make
make test
make install

wget后面的路径可以按需更改。安装过程比较耗时间，安装完成后可通过perl -version查看是否安装成功。

C++编译器

apt-get install g++

一般用于编译c++程序，缺少这个编译器进行make编译c++代码时，会报“g++: not found”的错误。

clone相关项目

下载下来所需要的两个项目（这里建议放到data目录下）：

git clone https://github.com/jvm-profiling-tools/async-profiler
git clone https://github.com/brendangregg/FlameGraph

编译项目

下载好以后，需要打开async-profiler文件，输入make指令进行编译：

cd async-profiler
make

生成文件

生成火焰图数据

可以从 github 上下载 async-profiler 的压缩包进行相关操作。进入async-profiler项目的目录下，然后输入如下指令：

./profiler.sh -d 60 -o collapsed -f /tmp/test_01.txt ${pid}

上面的-d表示的是持续时长，后面60代表持续采集时间60s，-o表示的是采集规范，这里用的是collapsed，-f后面的路径，表示的是数据采集后生成的数据存放的文件路径（这里放在了/tmp/test_01.txt），${pid}表示的是采集目标进程的pid，回车运行，运行期间阻塞，知道约定时间完成。运行完成后去tmp下看看有没有对应文件。

生成svg文件

上一步产生的文件里的内容，肉眼是很难看懂的，所以现在FlameGraph的作用就体现出来了，它可以读取该文件并生成直观的火焰图，现在进入该项目目录下面，执行如下语句：

perl flamegraph.pl --colors=java /tmp/test_01.txt > test_01.svg

因为是perl文件，这里使用perl指令运行该文件，后面–colors表示着色风格，这里是java，后面的是数据文件的路径，这里是刚刚上面生成的那个文件/tmp/test_01.txt，最后的test_01.svg就是最终生成的火焰图文件存放的路径和文件命名，这里是命名为test_01.svg并保存在当前路径，运行后看到该文件已经存在于当前目录下。

展示火焰图

现在下载下来该文件，使用浏览器打开，效果如下：

火焰图案例

火焰图案例

生成的火焰图案例如下：

火焰图案例

瓶颈点1

CoohuaAnalytics$KafkaConsumer:::send方法中Gzip压缩占比较高。已经定位到方法级别，再看代码就快速很多，直接找到具体位置，找到第一个消耗大户：Gzip压缩

火焰图-瓶颈点1

瓶颈点2

展开2这个波峰，查看到这个getOurStackTrace方法占用了大比例的CPU，怀疑代码里面频繁用丢异常的方式获取当前代码栈：

火焰图-瓶颈点2

直接看代码：

火焰图-瓶颈点2-代码

果然如推断，找到第二个CPU消耗大户：new Exception().getStackTrace()。

瓶颈点3

展开波峰3，可以看到是这个Gzip解压缩：

火焰图-瓶颈点3

定位到具体的代码，可以看到对每个请求的参数进行了gzip解压缩：

火焰图-瓶颈点3-代码

Search

    微信好友

    博士的沙漏

    Table of Contents