Java中9种常见的CMS GC问题分析与解决(上)

avatar
美团小编 @美团

1. 写在前面

| 本文主要针对 Hotspot VM 中“CMS + ParNew”组合的一些使用场景进行总结。重点通过部分源码对根因进行分析以及对排查方法进行总结,排查过程会省略较多,另外本文专业术语较多,有一定的阅读门槛,如未介绍清楚,还请自行查阅相关材料。

| 总字数 2 万左右(不包含代码片段),整体阅读时间约 30min ,文章较长,可以选择你感兴趣的场景进行研究。

1.1 引言

自 Sun 发布 Java 语言以来,开始使用 GC 技术来进行内存自动管理,避免了手动管理带来的悬挂指针(Dangling Pointer)问题,很大程度上提升了开发效率,从此 GC 技术也一举成名。GC 有着非常悠久的历史,1960 年有着“Lisp 之父”和“人工智能之父”之称的 John McCarthy 就在论文中发布了 GC 算法,60 年以来, GC 技术的发展也突飞猛进,但不管是多么前沿的收集器也都是基于三种基本算法的组合或应用,也就是说 GC 要解决的根本问题这么多年一直都没有变过。笔者认为,在不太远的将来, GC 技术依然不会过时,比起日新月异的新技术,GC 这门古典技术更值得我们学习。

目前,互联网上 Java 的 GC 资料要么是主要讲解理论,要么就是针对单一场景的 GC 问题进行了剖析,对整个体系总结的资料少之又少。前车之鉴,后事之师,美团的几位工程师搜集了内部各种 GC 问题的分析文章,并结合个人的理解做了一些总结,希望能起到“抛砖引玉”的作用,文中若有错误之处,还请大家不吝指正。

GC 问题处理能力能不能系统性掌握?一些影响因素都是互为因果的问题该怎么分析?比如一个服务 RT 突然上涨,有 GC 耗时增大、线程 Block 增多、慢查询增多、CPU 负载高四个表象,到底哪个是诱因?如何判断 GC 有没有问题?使用 CMS 有哪些常见问题?如何判断根因是什么?如何解决或避免这些问题?阅读完本文,相信你将会对 CMS GC 的问题处理有一个系统性的认知,更能游刃有余地解决这些问题,下面就让我们开始吧!

1.2 概览

想要系统性地掌握 GC 问题处理,笔者这里给出一个学习路径,整体文章的框架也是按照这个结构展开,主要分四大步。

  • 建立知识体系: 从 JVM 的内存结构到垃圾收集的算法和收集器,学习 GC 的基础知识,掌握一些常用的 GC 问题分析工具。

  • 确定评价指标: 了解基本 GC 的评价方法,摸清如何设定独立系统的指标,以及在业务场景中判断 GC 是否存在问题的手段。

  • 场景调优实践: 运用掌握的知识和系统评价指标,分析与解决九种 CMS 中常见 GC 问题场景。

  • 总结优化经验: 对整体过程做总结并提出笔者的几点建议,同时将总结到的经验完善到知识体系之中。

2. GC 基础

在正式开始前,先做些简要铺垫,介绍下 JVM 内存划分、收集算法、收集器等常用概念介绍,基础比较好的同学可以直接跳过这部分。

2.1 基础概念

  • GC: GC 本身有三种语义,下文需要根据具体场景带入不同的语义:

    • Garbage Collection:垃圾收集技术,名词。

    • Garbage Collector:垃圾收集器,名词。

    • Garbage Collecting:垃圾收集动作,动词。

  • Mutator: 生产垃圾的角色,也就是我们的应用程序,垃圾制造者,通过 Allocator 进行 allocate 和 free。

  • TLAB: Thread Local Allocation Buffer 的简写,基于 CAS 的独享线程(Mutator Threads)可以优先将对象分配在 Eden 中的一块内存,因为是 Java 线程独享的内存区没有锁竞争,所以分配速度更快,每个 TLAB 都是一个线程独享的。

  • Card Table: 中文翻译为卡表,主要是用来标记卡页的状态,每个卡表项对应一个卡页。当卡页中一个对象引用有写操作时,写屏障将会标记对象所在的卡表状态改为 dirty,卡表的本质是用来解决跨代引用的问题。具体怎么解决的可以参考 StackOverflow 上的这个问题 how-actually-card-table-and-writer-barrier-works,或者研读一下 cardTableRS.app 中的源码。

2.2 JVM 内存划分

从 JCP(Java Community Process)的官网中可以看到,目前 Java 版本最新已经到了 Java 16,未来的 Java 17 以及现在的 Java 11 和 Java 8 是 LTS 版本,JVM 规范也在随着迭代在变更,由于本文主要讨论 CMS,此处还是放 Java 8 的内存结构。

GC 主要工作在 Heap 区和 MetaSpace 区(上图蓝色部分),在 Direct Memory 中,如果使用的是 DirectByteBuffer,那么在分配内存不够时则是 GC 通过 Cleaner#clean 间接管理。

任何自动内存管理系统都会面临的步骤:为新对象分配空间,然后收集垃圾对象空间,下面我们就展开介绍一下这些基础知识。

2.3 分配对象

Java 中对象地址操作主要使用 Unsafe 调用了 C 的 allocate 和 free 两个方法,分配方法有两种:

  • 空闲链表(free list): 通过额外的存储记录空闲的地址,将随机 IO 变为顺序 IO,但带来了额外的空间消耗。

  • 碰撞指针(bump pointer): 通过一个指针作为分界点,需要分配内存时,仅需把指针往空闲的一端移动与对象大小相等的距离,分配效率较高,但使用场景有限。

2.4 收集对象

2.4.1 识别垃圾

  • 引用计数法(Reference Counting): 对每个对象的引用进行计数,每当有一个地方引用它时计数器 +1、引用失效则 -1,引用的计数放到对象头中,大于 0 的对象被认为是存活对象。虽然循环引用的问题可通过 Recycler 算法解决,但是在多线程环境下,引用计数变更也要进行昂贵的同步操作,性能较低,早期的编程语言会采用此算法。

  • 可达性分析,又称引用链法(Tracing GC): 从 GC Root 开始进行对象搜索,可以被搜索到的对象即为可达对象,此时还不足以判断对象是否存活/死亡,需要经过多次标记才能更加准确地确定,整个连通图之外的对象便可以作为垃圾被回收掉。目前 Java 中主流的虚拟机均采用此算法。

备注:引用计数法是可以处理循环引用问题的,下次面试时不要再这么说啦~ ~

2.4.2 收集算法

自从有自动内存管理出现之时就有的一些收集算法,不同的收集器也是在不同场景下进行组合。

  • Mark-Sweep(标记-清除): 回收过程主要分为两个阶段,第一阶段为追踪(Tracing)阶段,即从 GC Root 开始遍历对象图,并标记(Mark)所遇到的每个对象,第二阶段为清除(Sweep)阶段,即回收器检查堆中每一个对象,并将所有未被标记的对象进行回收,整个过程不会发生对象移动。整个算法在不同的实现中会使用三色抽象(Tricolour Abstraction)、位图标记(BitMap)等技术来提高算法的效率,存活对象较多时较高效。

  • Mark-Compact (标记-整理): 这个算法的主要目的就是解决在非移动式回收器中都会存在的碎片化问题,也分为两个阶段,第一阶段与 Mark-Sweep 类似,第二阶段则会对存活对象按照整理顺序(Compaction Order)进行整理。主要实现有双指针(Two-Finger)回收算法、滑动回收(Lisp2)算法和引线整理(Threaded Compaction)算法等。

  • Copying(复制): 将空间分为两个大小相同的 From 和 To 两个半区,同一时间只会使用其中一个,每次进行回收时将一个半区的存活对象通过复制的方式转移到另一个半区。有递归(Robert R. Fenichel 和 Jerome C. Yochelson提出)和迭代(Cheney 提出)算法,以及解决了前两者递归栈、缓存行等问题的近似优先搜索算法。复制算法可以通过碰撞指针的方式进行快速地分配内存,但是也存在着空间利用率不高的缺点,另外就是存活对象比较大时复制的成本比较高。

三种算法在是否移动对象、空间和时间方面的一些对比,假设存活对象数量为 L、堆空间大小为 H,则:

把 mark、sweep、compaction、copying 这几种动作的耗时放在一起看,大致有这样的关系:

虽然 compaction 与 copying 都涉及移动对象,但取决于具体算法,compaction 可能要先计算一次对象的目标地址,然后修正指针,最后再移动对象。copying 则可以把这几件事情合为一体来做,所以可以快一些。另外,还需要留意 GC 带来的开销不能只看 Collector 的耗时,还得看 Allocator 。如果能保证内存没碎片,分配就可以用 pointer bumping 方式,只需要挪一个指针就完成了分配,非常快。而如果内存有碎片就得用 freelist 之类的方式管理,分配速度通常会慢一些。

2.5 收集器

目前在 Hotspot VM 中主要有分代收集和分区收集两大类,具体可以看下面的这个图,不过未来会逐渐向分区收集发展。在美团内部,有部分业务尝试用了 ZGC(感兴趣的同学可以学习下这篇文章 新一代垃圾回收器ZGC的探索与实践),其余基本都停留在 CMS 和 G1 上。另外在 JDK11 后提供了一个不执行任何垃圾回收动作的回收器 Epsilon(A No-Op Garbage Collector)用作性能分析。另外一个就是 Azul 的 Zing JVM,其 C4(Concurrent Continuously Compacting Collector)收集器也在业内有一定的影响力。

备注:值得一提的是,早些年国内 GC 技术的布道者 RednaxelaFX (江湖人称 R 大)也曾就职于 Azul,本文的一部分材料也参考了他的一些文章。

2.5.1 分代收集器

  • ParNew: 一款多线程的收集器,采用复制算法,主要工作在 Young 区,可以通过 -XX:ParallelGCThreads 参数来控制收集的线程数,整个过程都是 STW 的,常与 CMS 组合使用。

  • CMS: 以获取最短回收停顿时间为目标,采用“标记-清除”算法,分 4 大步进行垃圾收集,其中初始标记和重新标记会 STW ,多数应用于互联网站或者 B/S 系统的服务器端上,JDK9 被标记弃用,JDK14 被删除,详情可见 JEP 363

2.5.2 分区收集器

  • G1: 一种服务器端的垃圾收集器,应用在多处理器和大容量内存环境中,在实现高吞吐量的同时,尽可能地满足垃圾收集暂停时间的要求。

  • ZGC: JDK11 中推出的一款低延迟垃圾回收器,适用于大内存低延迟服务的内存管理和回收,SPECjbb 2015 基准测试,在 128G 的大堆下,最大停顿时间才 1.68 ms,停顿时间远胜于 G1 和 CMS。

  • Shenandoah: 由 Red Hat 的一个团队负责开发,与 G1 类似,基于 Region 设计的垃圾收集器,但不需要 Remember Set 或者 Card Table 来记录跨 Region 引用,停顿时间和堆的大小没有任何关系。停顿时间与 ZGC 接近,下图为与 CMS 和 G1 等收集器的 benchmark。

2.5.3 常用收集器

目前使用最多的是 CMS 和 G1 收集器,二者都有分代的概念,主要内存结构如下:

2.5.4 其他收集器

以上仅列出常见收集器,除此之外还有很多,如 Metronome、Stopless、Staccato、Chicken、Clover 等实时回收器,Sapphire、Compressor、Pauseless 等并发复制/整理回收器,Doligez-Leroy-Conthier 等标记整理回收器,由于篇幅原因,不在此一一介绍。

2.6 常用工具

工欲善其事,必先利其器,此处列出一些笔者常用的工具,具体情况大家可以自由选择,本文的问题都是使用这些工具来定位和分析的。

2.6.1 命令行终端

  • 标准终端类:jps、jinfo、jstat、jstack、jmap
  • 功能整合类:jcmd、vjtools、arthas、greys

2.6.2 可视化界面

  • 简易:JConsole、JVisualvm、HA、GCHisto、GCViewer
  • 进阶:MAT、JProfiler

命令行推荐 arthas ,可视化界面推荐 JProfiler,此外还有一些在线的平台 gceasyheapherofastthread ,美团内部的 Scalpel(一款自研的 JVM 问题诊断工具,暂时未开源)也比较好用。

3. GC 问题判断

在做 GC 问题排查和优化之前,我们需要先来明确下到底是不是 GC 直接导致的问题,或者应用代码导致的 GC 异常,最终出现问题。

3.1 判断 GC 有没有问题?

3.1.1 设定评价标准

评判 GC 的两个核心指标:

  • 延迟(Latency): 也可以理解为最大停顿时间,即垃圾收集过程中一次 STW 的最长时间,越短越好,一定程度上可以接受频次的增大,GC 技术的主要发展方向。

  • 吞吐量(Throughput): 应用系统的生命周期内,由于 GC 线程会占用 Mutator 当前可用的 CPU 时钟周期,吞吐量即为 Mutator 有效花费的时间占系统总运行时间的百分比,例如系统运行了 100 min,GC 耗时 1 min,则系统吞吐量为 99%,吞吐量优先的收集器可以接受较长的停顿。

目前各大互联网公司的系统基本都更追求低延时,避免一次 GC 停顿的时间过长对用户体验造成损失,衡量指标需要结合一下应用服务的 SLA,主要如下两点来判断:

简而言之,即为一次停顿的时间不超过应用服务的 TP9999,GC 的吞吐量不小于 99.99%。举个例子,假设某个服务 A 的 TP9999 为 80 ms,平均 GC 停顿为 30 ms,那么该服务的最大停顿时间最好不要超过 80 ms,GC 频次控制在 5 min 以上一次。如果满足不了,那就需要调优或者通过更多资源来进行并联冗余。(大家可以先停下来,看看监控平台上面的 gc.meantime 分钟级别指标,如果超过了 6 ms 那单机 GC 吞吐量就达不到 4 个 9 了。)

备注:除了这两个指标之外还有 Footprint(资源量大小测量)、反应速度等指标,互联网这种实时系统追求低延迟,而很多嵌入式系统则追求 Footprint。

3.1.2 读懂 GC Cause

拿到 GC 日志,我们就可以简单分析 GC 情况了,通过一些工具,我们可以比较直观地看到 Cause 的分布情况,如下图就是使用 gceasy 绘制的图表:

如上图所示,我们很清晰的就能知道是什么原因引起的 GC,以及每次的时间花费情况,但是要分析 GC 的问题,先要读懂 GC Cause,即 JVM 什么样的条件下选择进行 GC 操作,具体 Cause 的分类可以看一下 Hotspot 源码:src/share/vm/gc/shared/gcCause.hpp 和 src/share/vm/gc/shared/gcCause.cpp 中。

const char* GCCause::to_string(GCCause::Cause cause) {
  switch (cause) {
    case _java_lang_system_gc:
      return "System.gc()";

    case _full_gc_alot:
      return "FullGCAlot";

    case _scavenge_alot:
      return "ScavengeAlot";

    case _allocation_profiler:
      return "Allocation Profiler";

    case _jvmti_force_gc:
      return "JvmtiEnv ForceGarbageCollection";

    case _gc_locker:
      return "GCLocker Initiated GC";

    case _heap_inspection:
      return "Heap Inspection Initiated GC";

    case _heap_dump:
      return "Heap Dump Initiated GC";

    case _wb_young_gc:
      return "WhiteBox Initiated Young GC";

    case _wb_conc_mark:
      return "WhiteBox Initiated Concurrent Mark";

    case _wb_full_gc:
      return "WhiteBox Initiated Full GC";

    case _no_gc:
      return "No GC";

    case _allocation_failure:
      return "Allocation Failure";

    case _tenured_generation_full:
      return "Tenured Generation Full";

    case _metadata_GC_threshold:
      return "Metadata GC Threshold";

    case _metadata_GC_clear_soft_refs:
      return "Metadata GC Clear Soft References";

    case _cms_generation_full:
      return "CMS Generation Full";

    case _cms_initial_mark:
      return "CMS Initial Mark";

    case _cms_final_remark:
      return "CMS Final Remark";

    case _cms_concurrent_mark:
      return "CMS Concurrent Mark";

    case _old_generation_expanded_on_last_scavenge:
      return "Old Generation Expanded On Last Scavenge";

    case _old_generation_too_full_to_scavenge:
      return "Old Generation Too Full To Scavenge";

    case _adaptive_size_policy:
      return "Ergonomics";

    case _g1_inc_collection_pause:
      return "G1 Evacuation Pause";

    case _g1_humongous_allocation:
      return "G1 Humongous Allocation";

    case _dcmd_gc_run:
      return "Diagnostic Command";

    case _last_gc_cause:
      return "ILLEGAL VALUE - last gc cause - ILLEGAL VALUE";

    default:
      return "unknown GCCause";
  }
  ShouldNotReachHere();
}

重点需要关注的几个GC Cause:

  • System.gc(): 手动触发GC操作。

  • CMS: CMS GC 在执行过程中的一些动作,重点关注 CMS Initial Mark 和 CMS Final Remark 两个 STW 阶段。

  • Promotion Failure: Old 区没有足够的空间分配给 Young 区晋升的对象(即使总可用内存足够大)。

  • Concurrent Mode Failure: CMS GC 运行期间,Old 区预留的空间不足以分配给新的对象,此时收集器会发生退化,严重影响 GC 性能,下面的一个案例即为这种场景。

  • GCLocker Initiated GC: 如果线程执行在 JNI 临界区时,刚好需要进行 GC,此时 GC Locker 将会阻止 GC 的发生,同时阻止其他线程进入 JNI 临界区,直到最后一个线程退出临界区时触发一次 GC。

什么时机使用这些 Cause 触发回收,大家可以看一下 CMS 的代码,这里就不讨论了,具体在 /src/hotspot/share/gc/cms/concurrentMarkSweepGeneration.cpp 中。

bool CMSCollector::shouldConcurrentCollect() {
  LogTarget(Trace, gc) log;

  if (_full_gc_requested) {
    log.print("CMSCollector: collect because of explicit  gc request (or GCLocker)");
    return true;
  }

  FreelistLocker x(this);
  // ------------------------------------------------------------------
  // Print out lots of information which affects the initiation of
  // a collection.
  if (log.is_enabled() && stats().valid()) {
    log.print("CMSCollector shouldConcurrentCollect: ");

    LogStream out(log);
    stats().print_on(&out);

    log.print("time_until_cms_gen_full %3.7f", stats().time_until_cms_gen_full());
    log.print("free=" SIZE_FORMAT, _cmsGen->free());
    log.print("contiguous_available=" SIZE_FORMAT, _cmsGen->contiguous_available());
    log.print("promotion_rate=%g", stats().promotion_rate());
    log.print("cms_allocation_rate=%g", stats().cms_allocation_rate());
    log.print("occupancy=%3.7f", _cmsGen->occupancy());
    log.print("initiatingOccupancy=%3.7f", _cmsGen->initiating_occupancy());
    log.print("cms_time_since_begin=%3.7f", stats().cms_time_since_begin());
    log.print("cms_time_since_end=%3.7f", stats().cms_time_since_end());
    log.print("metadata initialized %d", MetaspaceGC::should_concurrent_collect());
  }
  // ------------------------------------------------------------------

  // If the estimated time to complete a cms collection (cms_duration())
  // is less than the estimated time remaining until the cms generation
  // is full, start a collection.
  if (!UseCMSInitiatingOccupancyOnly) {
    if (stats().valid()) {
      if (stats().time_until_cms_start() == 0.0) {
        return true;
      }
    } else {
   
      if (_cmsGen->occupancy() >= _bootstrap_occupancy) {
        log.print(" CMSCollector: collect for bootstrapping statistics: occupancy = %f, boot occupancy = %f",
                  _cmsGen->occupancy(), _bootstrap_occupancy);
        return true;
      }
    }
  }
  if (_cmsGen->should_concurrent_collect()) {
    log.print("CMS old gen initiated");
    return true;
  }

  CMSHeap* heap = CMSHeap::heap();
  if (heap->incremental_collection_will_fail(true /* consult_young */)) {
    log.print("CMSCollector: collect because incremental collection will fail ");
    return true;
  }

  if (MetaspaceGC::should_concurrent_collect()) {
    log.print("CMSCollector: collect for metadata allocation ");
    return true;
  }

  // CMSTriggerInterval starts a CMS cycle if enough time has passed.
  if (CMSTriggerInterval >= 0) {
    if (CMSTriggerInterval == 0) {
      // Trigger always
      return true;
    }

    // Check the CMS time since begin (we do not check the stats validity
    // as we want to be able to trigger the first CMS cycle as well)
    if (stats().cms_time_since_begin() >= (CMSTriggerInterval / ((double) MILLIUNITS))) {
      if (stats().valid()) {
        log.print("CMSCollector: collect because of trigger interval (time since last begin %3.7f secs)",
                  stats().cms_time_since_begin());
      } else {
        log.print("CMSCollector: collect because of trigger interval (first collection)");
      }
      return true;
    }
  }

  return false;
}

3.2 判断是不是 GC 引发的问题?

到底是结果(现象)还是原因,在一次 GC 问题处理的过程中,如何判断是 GC 导致的故障,还是系统本身引发 GC 问题。这里继续拿在本文开头提到的一个 Case:“GC 耗时增大、线程 Block 增多、慢查询增多、CPU 负载高等四个表象,如何判断哪个是根因?”,笔者这里根据自己的经验大致整理了四种判断方法供参考:

  • 时序分析: 先发生的事件是根因的概率更大,通过监控手段分析各个指标的异常时间点,还原事件时间线,如先观察到 CPU 负载高(要有足够的时间 Gap),那么整个问题影响链就可能是:CPU 负载高 -> 慢查询增多 -> GC 耗时增大 -> 线程Block增多 -> RT 上涨。

  • 概率分析: 使用统计概率学,结合历史问题的经验进行推断,由近到远按类型分析,如过往慢查的问题比较多,那么整个问题影响链就可能是:慢查询增多 -> GC 耗时增大 -> CPU 负载高 -> 线程 Block 增多 -> RT上涨。

  • 实验分析: 通过故障演练等方式对问题现场进行模拟,触发其中部分条件(一个或多个),观察是否会发生问题,如只触发线程 Block 就会发生问题,那么整个问题影响链就可能是:线程Block增多 -> CPU 负载高 -> 慢查询增多 -> GC 耗时增大 -> RT 上涨。

  • 反证分析: 对其中某一表象进行反证分析,即判断表象的发不发生跟结果是否有相关性,例如我们从整个集群的角度观察到某些节点慢查和 CPU 都正常,但也出了问题,那么整个问题影响链就可能是:GC 耗时增大 -> 线程 Block 增多 -> RT 上涨。

不同的根因,后续的分析方法是完全不同的。如果是 CPU 负载高那可能需要用火焰图看下热点、如果是慢查询增多那可能需要看下 DB 情况、如果是线程 Block 引起那可能需要看下锁竞争的情况,最后如果各个表象证明都没有问题,那可能 GC 确实存在问题,可以继续分析 GC 问题了。

3.3 问题分类导读

3.3.1 Mutator 类型

Mutator 的类型根据对象存活时间比例图来看主要分为两种,在弱分代假说中也提到类似的说法,如下图所示 “Survival Time” 表示对象存活时间,“Rate” 表示对象分配比例:

  • IO 交互型: 互联网上目前大部分的服务都属于该类型,例如分布式 RPC、MQ、HTTP 网关服务等,对内存要求并不大,大部分对象在 TP9999 的时间内都会死亡, Young 区越大越好。

  • MEM 计算型: 主要是分布式数据计算 Hadoop,分布式存储 HBase、Cassandra,自建的分布式缓存等,对内存要求高,对象存活时间长,Old 区越大越好。

当然,除了二者之外还有介于两者之间的场景,本篇文章主要讨论第一种情况。对象 Survival Time 分布图,对我们设置 GC 参数有着非常重要的指导意义,如下图就可以简单推算分代的边界。

3.3.2 GC 问题分类

笔者选取了九种不同类型的 GC 问题,覆盖了大部分场景,如果有更好的场景,欢迎在评论区给出。

  • Unexpected GC: 意外发生的 GC,实际上不需要发生,我们可以通过一些手段去避免。

    • Space Shock: 空间震荡问题,参见“场景一:动态扩容引起的空间震荡”。
    • Explicit GC: 显示执行 GC 问题,参见“场景二:显式 GC 的去与留”。
  • Partial GC: 部分收集操作的 GC,只对某些分代/分区进行回收。

    • Young GC: 分代收集里面的 Young 区收集动作,也可以叫做 Minor GC。

      • ParNew: Young GC 频繁,参见“场景四:过早晋升”。
    • Old GC: 分代收集里面的 Old 区收集动作,也可以叫做 Major GC,有些也会叫做 Full GC,但其实这种叫法是不规范的,在 CMS 发生 Foreground GC 时才是 Full GC,CMSScavengeBeforeRemark 参数也只是在 Remark 前触发一次Young GC。

      • CMS: Old GC 频繁,参见“场景五:CMS Old GC 频繁”。
      • CMS: Old GC 不频繁但单次耗时大,参见“场景六:单次 CMS Old GC 耗时长”。
  • Full GC: 全量收集的 GC,对整个堆进行回收,STW 时间会比较长,一旦发生,影响较大,也可以叫做 Major GC,参见“场景七:内存碎片&收集器退化”。

  • MetaSpace: 元空间回收引发问题,参见“场景三:MetaSpace 区 OOM”。

  • Direct Memory: 直接内存(也可以称作为堆外内存)回收引发问题,参见“场景八:堆外内存 OOM”。

  • JNI: 本地 Native 方法引发问题,参见“场景九:JNI 引发的 GC 问题”。

3.3.3 排查难度

一个问题的解决难度跟它的常见程度成反比,大部分我们都可以通过各种搜索引擎找到类似的问题,然后用同样的手段尝试去解决。当一个问题在各种网站上都找不到相似的问题时,那么可能会有两种情况,一种这不是一个问题,另一种就是遇到一个隐藏比较深的问题,遇到这种问题可能就要深入到源码级别去调试了。以下 GC 问题场景,排查难度从上到下依次递增。

4. 常见场景分析与解决

4.1 场景一:动态扩容引起的空间震荡

4.1.1 现象

服务刚刚启动时 GC 次数较多,最大空间剩余很多但是依然发生 GC,这种情况我们可以通过观察 GC 日志或者通过监控工具来观察堆的空间变化情况即可。GC Cause 一般为 Allocation Failure,且在 GC 日志中会观察到经历一次 GC ,堆内各个空间的大小会被调整,如下图所示:

4.1.2 原因

在 JVM 的参数中 -Xms-Xmx 设置的不一致,在初始化时只会初始 -Xms 大小的空间存储信息,每当空间不够用时再向操作系统申请,这样的话必然要进行一次 GC。具体是通过 ConcurrentMarkSweepGeneration::compute_new_size() 方法计算新的空间大小:

void ConcurrentMarkSweepGeneration::compute_new_size() {
  assert_locked_or_safepoint(Heap_lock);

  // If incremental collection failed, we just want to expand
  // to the limit.
  if (incremental_collection_failed()) {
    clear_incremental_collection_failed();
    grow_to_reserved();
    return;
  }

  // The heap has been compacted but not reset yet.
  // Any metric such as free() or used() will be incorrect.

  CardGeneration::compute_new_size();

  // Reset again after a possible resizing
  if (did_compact()) {
    cmsSpace()->reset_after_compaction();
  }
}

另外,如果空间剩余很多时也会进行缩容操作,JVM 通过 -XX:MinHeapFreeRatio-XX:MaxHeapFreeRatio 来控制扩容和缩容的比例,调节这两个值也可以控制伸缩的时机,例如扩容便是使用 GenCollectedHeap::expand_heap_and_allocate() 来完成的,代码如下:

HeapWord* GenCollectedHeap::expand_heap_and_allocate(size_t size, bool   is_tlab) {
  HeapWord* result = NULL;
  if (_old_gen->should_allocate(size, is_tlab)) {
    result = _old_gen->expand_and_allocate(size, is_tlab);
  }
  if (result == NULL) {
    if (_young_gen->should_allocate(size, is_tlab)) {
      result = _young_gen->expand_and_allocate(size, is_tlab);
    }
  }
  assert(result == NULL || is_in_reserved(result), "result not in heap");
  return result;
}

整个伸缩的模型理解可以看这个图,当 committed 的空间大小超过了低水位/高水位的大小,capacity 也会随之调整:

4.1.3 策略

定位:观察 CMS GC 触发时间点 Old/MetaSpace 区的 committed 占比是不是一个固定的值,或者像上文提到的观察总的内存使用率也可以。

解决:尽量将成对出现的空间大小配置参数设置成固定的,如 -Xms-Xmx-XX:MaxNewSize-XX:NewSize-XX:MetaSpaceSize-XX:MaxMetaSpaceSize 等。

4.1.4 小结

一般来说,我们需要保证 Java 虚拟机的堆是稳定的,确保 -Xms-Xmx 设置的是一个值(即初始值和最大值一致),获得一个稳定的堆,同理在 MetaSpace 区也有类似的问题。不过在不追求停顿时间的情况下震荡的空间也是有利的,可以动态地伸缩以节省空间,例如作为富客户端的 Java 应用。

这个问题虽然初级,但是发生的概率还真不小,尤其是在一些规范不太健全的情况下。

4.2 场景二:显式 GC 的去与留

4.2.1 现象

除了扩容缩容会触发 CMS GC 之外,还有 Old 区达到回收阈值、MetaSpace 空间不足、Young 区晋升失败、大对象担保失败等几种触发条件,如果这些情况都没有发生却触发了 GC ?这种情况有可能是代码中手动调用了 System.gc 方法,此时可以找到 GC 日志中的 GC Cause 确认下。那么这种 GC 到底有没有问题,翻看网上的一些资料,有人说可以添加 -XX:+DisableExplicitGC 参数来避免这种 GC,也有人说不能加这个参数,加了就会影响 Native Memory 的回收。先说结论,笔者这里建议保留 System.gc,那为什么要保留?我们一起来分析下。

4.2.2 原因

找到 System.gc 在 Hotspot 中的源码,可以发现增加 -XX:+DisableExplicitGC 参数后,这个方法变成了一个空方法,如果没有加的话便会调用 Universe::heap()::collect 方法,继续跟进到这个方法中,发现 System.gc 会引发一次 STW 的 Full GC,对整个堆做收集。

JVM_ENTRY_NO_ENV(void, JVM_GC(void))
  JVMWrapper("JVM_GC");
  if (!DisableExplicitGC) {
    Universe::heap()->collect(GCCause::_java_lang_system_gc);
  }
JVM_END
void GenCollectedHeap::collect(GCCause::Cause cause) {
  if (cause == GCCause::_wb_young_gc) {
    // Young collection for the WhiteBox API.
    collect(cause, YoungGen);
  } else {
#ifdef ASSERT
  if (cause == GCCause::_scavenge_alot) {
    // Young collection only.
    collect(cause, YoungGen);
  } else {
    // Stop-the-world full collection.
    collect(cause, OldGen);
  }
#else
    // Stop-the-world full collection.
    collect(cause, OldGen);
#endif
  }
}

保留 System.gc

此处补充一个知识点,CMS GC 共分为 Background 和 Foreground 两种模式,前者就是我们常规理解中的并发收集,可以不影响正常的业务线程运行,但 Foreground Collector 却有很大的差异,他会进行一次压缩式 GC。此压缩式 GC 使用的是跟 Serial Old GC 一样的 Lisp2 算法,其使用 Mark-Compact 来做 Full GC,一般称之为 MSC(Mark-Sweep-Compact),它收集的范围是 Java 堆的 Young 区和 Old 区以及 MetaSpace。由上面的算法章节中我们知道 compact 的代价是巨大的,那么使用 Foreground Collector 时将会带来非常长的 STW。如果在应用程序中 System.gc 被频繁调用,那就非常危险了。

去掉 System.gc

如果禁用掉的话就会带来另外一个内存泄漏问题,此时就需要说一下 DirectByteBuffer,它有着零拷贝等特点,被 Netty 等各种 NIO 框架使用,会使用到堆外内存。堆内存由 JVM 自己管理,堆外内存必须要手动释放,DirectByteBuffer 没有 Finalizer,它的 Native Memory 的清理工作是通过 sun.misc.Cleaner 自动完成的,是一种基于 PhantomReference 的清理工具,比普通的 Finalizer 轻量些。

为 DirectByteBuffer 分配空间过程中会显式调用 System.gc ,希望通过 Full GC 来强迫已经无用的 DirectByteBuffer 对象释放掉它们关联的 Native Memory,下面为代码实现:

// These methods should be called whenever direct memory is allocated or
// freed.  They allow the user to control the amount of direct memory
// which a process may access.  All sizes are specified in bytes.
static void reserveMemory(long size) {

    synchronized (Bits.class) {
        if (!memoryLimitSet && VM.isBooted()) {
            maxMemory = VM.maxDirectMemory();
            memoryLimitSet = true;
        }
        if (size <= maxMemory - reservedMemory) {
            reservedMemory += size;
            return;
        }
    }

    System.gc();
    try {
        Thread.sleep(100);
    } catch (InterruptedException x) {
        // Restore interrupt status
        Thread.currentThread().interrupt();
    }
    synchronized (Bits.class) {
        if (reservedMemory + size > maxMemory)
            throw new OutOfMemoryError("Direct buffer memory");
        reservedMemory += size;
    }

}

HotSpot VM 只会在 Old GC 的时候才会对 Old 中的对象做 Reference Processing,而在 Young GC 时只会对 Young 里的对象做 Reference Processing。Young 中的 DirectByteBuffer 对象会在 Young GC 时被处理,也就是说,做 CMS GC 的话会对 Old 做 Reference Processing,进而能触发 Cleaner 对已死的 DirectByteBuffer 对象做清理工作。但如果很长一段时间里没做过 GC 或者只做了 Young GC 的话则不会在 Old 触发 Cleaner 的工作,那么就可能让本来已经死亡,但已经晋升到 Old 的 DirectByteBuffer 关联的 Native Memory 得不到及时释放。这几个实现特征使得依赖于 System.gc 触发 GC 来保证 DirectByteMemory 的清理工作能及时完成。如果打开了 -XX:+DisableExplicitGC,清理工作就可能得不到及时完成,于是就有发生 Direct Memory 的 OOM。

4.2.3 策略

通过上面的分析看到,无论是保留还是去掉都会有一定的风险点,不过目前互联网中的 RPC 通信会大量使用 NIO,所以笔者在这里建议保留。此外 JVM 还提供了 -XX:+ExplicitGCInvokesConcurrent-XX:+ExplicitGCInvokesConcurrentAndUnloadsClasses 参数来将 System.gc 的触发类型从 Foreground 改为 Background,同时 Background 也会做 Reference Processing,这样的话就能大幅降低了 STW 开销,同时也不会发生 NIO Direct Memory OOM。

4.2.4 小结

不止 CMS,在 G1 或 ZGC中开启 ExplicitGCInvokesConcurrent 模式,都会采用高性能的并发收集方式进行收集,不过还是建议在代码规范方面也要做好约束,规范好 System.gc 的使用。

P.S. HotSpot 对 System.gc 有特别处理,最主要的地方体现在一次 System.gc 是否与普通 GC 一样会触发 GC 的统计/阈值数据的更新,HotSpot 里的许多 GC 算法都带有自适应的功能,会根据先前收集的效率来决定接下来的 GC 中使用的参数,但 System.gc 默认不更新这些统计数据,避免用户强行 GC 对这些自适应功能的干扰(可以参考 -XX:+UseAdaptiveSizePolicyWithSystemGC 参数,默认是 false)。

4.3 场景三:MetaSpace 区 OOM

4.3.1 现象

JVM 在启动后或者某个时间点开始,MetaSpace 的已使用大小在持续增长,同时每次 GC 也无法释放,调大 MetaSpace 空间也无法彻底解决

4.3.2 原因

在讨论为什么会 OOM 之前,我们先来看一下这个区里面会存什么数据,Java7 之前字符串常量池被放到了 Perm 区,所有被 intern 的 String 都会被存在这里,由于 String.intern 是不受控的,所以 -XX:MaxPermSize 的值也不太好设置,经常会出现 java.lang.OutOfMemoryError: PermGen space 异常,所以在 Java7 之后常量池等字面量(Literal)、类静态变量(Class Static)、符号引用(Symbols Reference)等几项被移到 Heap 中。而 Java8 之后 PermGen 也被移除,取而代之的是 MetaSpace。

在最底层,JVM 通过 mmap 接口向操作系统申请内存映射,每次申请 2MB 空间,这里是虚拟内存映射,不是真的就消耗了主存的 2MB,只有之后在使用的时候才会真的消耗内存。申请的这些内存放到一个链表中 VirtualSpaceList,作为其中的一个 Node。

在上层,MetaSpace 主要由 Klass Metaspace 和 NoKlass Metaspace 两大部分组成。

  • Klass MetaSpace: 就是用来存 Klass 的,就是 Class 文件在 JVM 里的运行时数据结构,这部分默认放在 Compressed Class Pointer Space 中,是一块连续的内存区域,紧接着 Heap。Compressed Class Pointer Space 不是必须有的,如果设置了 -XX:-UseCompressedClassPointers,或者 -Xmx 设置大于 32 G,就不会有这块内存,这种情况下 Klass 都会存在 NoKlass Metaspace 里。
  • NoKlass MetaSpace: 专门来存 Klass 相关的其他的内容,比如 Method,ConstantPool 等,可以由多块不连续的内存组成。虽然叫做 NoKlass Metaspace,但是也其实可以存 Klass 的内容,上面已经提到了对应场景。

具体的定义都可以在源码 shared/vm/memory/metaspace.hpp 中找到:

class Metaspace : public AllStatic {

  friend class MetaspaceShared;

 public:
  enum MetadataType {
    ClassType,
    NonClassType,
    MetadataTypeCount
  };
  enum MetaspaceType {
    ZeroMetaspaceType = 0,
    StandardMetaspaceType = ZeroMetaspaceType,
    BootMetaspaceType = StandardMetaspaceType + 1,
    AnonymousMetaspaceType = BootMetaspaceType + 1,
    ReflectionMetaspaceType = AnonymousMetaspaceType + 1,
    MetaspaceTypeCount
  };

 private:

  // Align up the word size to the allocation word size
  static size_t align_word_size_up(size_t);

  // Aligned size of the metaspace.
  static size_t _compressed_class_space_size;

  static size_t compressed_class_space_size() {
    return _compressed_class_space_size;
  }

  static void set_compressed_class_space_size(size_t size) {
    _compressed_class_space_size = size;
  }

  static size_t _first_chunk_word_size;
  static size_t _first_class_chunk_word_size;

  static size_t _commit_alignment;
  static size_t _reserve_alignment;
  DEBUG_ONLY(static bool   _frozen;)

  // Virtual Space lists for both classes and other metadata
  static metaspace::VirtualSpaceList* _space_list;
  static metaspace::VirtualSpaceList* _class_space_list;

  static metaspace::ChunkManager* _chunk_manager_metadata;
  static metaspace::ChunkManager* _chunk_manager_class;

  static const MetaspaceTracer* _tracer;
}

MetaSpace 的对象为什么无法释放,我们看下面两点:

  • MetaSpace 内存管理: 类和其元数据的生命周期与其对应的类加载器相同,只要类的类加载器是存活的,在 Metaspace 中的类元数据也是存活的,不能被回收。每个加载器有单独的存储空间,通过 ClassLoaderMetaspace 来进行管理 SpaceManager* 的指针,相互隔离的。

  • MetaSpace 弹性伸缩: 由于 MetaSpace 空间和 Heap 并不在一起,所以这块的空间可以不用设置或者单独设置,一般情况下避免 MetaSpace 耗尽 VM 内存都会设置一个 MaxMetaSpaceSize,在运行过程中,如果实际大小小于这个值,JVM 就会通过 -XX:MinMetaspaceFreeRatio-XX:MaxMetaspaceFreeRatio 两个参数动态控制整个 MetaSpace 的大小,具体使用可以看 MetaSpaceGC::compute_new_size() 方法(下方代码),这个方法会在 CMSCollector 和 G1CollectorHeap 等几个收集器执行 GC 时调用。这个里面会根据 used_after_gcMinMetaspaceFreeRatioMaxMetaspaceFreeRatio 这三个值计算出来一个新的 _capacity_until_GC 值(水位线)。然后根据实际的 _capacity_until_GC 值使用 MetaspaceGC::inc_capacity_until_GC()MetaspaceGC::dec_capacity_until_GC() 进行 expand 或 shrink,这个过程也可以参照场景一中的伸缩模型进行理解。

void MetaspaceGC::compute_new_size() {
  assert(_shrink_factor <= 100, "invalid shrink factor");
  uint current_shrink_factor = _shrink_factor;
  _shrink_factor = 0;
  const size_t used_after_gc = MetaspaceUtils::committed_bytes();
  const size_t capacity_until_GC = MetaspaceGC::capacity_until_GC();

  const double minimum_free_percentage = MinMetaspaceFreeRatio / 100.0;
  const double maximum_used_percentage = 1.0 - minimum_free_percentage;

  const double min_tmp = used_after_gc / maximum_used_percentage;
  size_t minimum_desired_capacity =
    (size_t)MIN2(min_tmp, double(max_uintx));
  // Don't shrink less than the initial generation size
  minimum_desired_capacity = MAX2(minimum_desired_capacity,
                                  MetaspaceSize);

  log_trace(gc, metaspace)("MetaspaceGC::compute_new_size: ");
  log_trace(gc, metaspace)("    minimum_free_percentage: %6.2f  maximum_used_percentage: %6.2f",
                           minimum_free_percentage, maximum_used_percentage);
  log_trace(gc, metaspace)("     used_after_gc       : %6.1fKB", used_after_gc / (double) K);


  size_t shrink_bytes = 0;
  if (capacity_until_GC < minimum_desired_capacity) {
    // If we have less capacity below the metaspace HWM, then
    // increment the HWM.
    size_t expand_bytes = minimum_desired_capacity - capacity_until_GC;
    expand_bytes = align_up(expand_bytes, Metaspace::commit_alignment());
    // Don't expand unless it's significant
    if (expand_bytes >= MinMetaspaceExpansion) {
      size_t new_capacity_until_GC = 0;
      bool succeeded = MetaspaceGC::inc_capacity_until_GC(expand_bytes, &new_capacity_until_GC);
      assert(succeeded, "Should always succesfully increment HWM when at safepoint");

      Metaspace::tracer()->report_gc_threshold(capacity_until_GC,
                                               new_capacity_until_GC,
                                               MetaspaceGCThresholdUpdater::ComputeNewSize);
      log_trace(gc, metaspace)("    expanding:  minimum_desired_capacity: %6.1fKB  expand_bytes: %6.1fKB  MinMetaspaceExpansion: %6.1fKB  new metaspace HWM:  %6.1fKB",
                               minimum_desired_capacity / (double) K,
                               expand_bytes / (double) K,
                               MinMetaspaceExpansion / (double) K,
                               new_capacity_until_GC / (double) K);
    }
    return;
  }

  // No expansion, now see if we want to shrink
  // We would never want to shrink more than this
  assert(capacity_until_GC >= minimum_desired_capacity,
         SIZE_FORMAT " >= " SIZE_FORMAT,
         capacity_until_GC, minimum_desired_capacity);
  size_t max_shrink_bytes = capacity_until_GC - minimum_desired_capacity;

  // Should shrinking be considered?
  if (MaxMetaspaceFreeRatio < 100) {
    const double maximum_free_percentage = MaxMetaspaceFreeRatio / 100.0;
    const double minimum_used_percentage = 1.0 - maximum_free_percentage;
    const double max_tmp = used_after_gc / minimum_used_percentage;
    size_t maximum_desired_capacity = (size_t)MIN2(max_tmp, double(max_uintx));
    maximum_desired_capacity = MAX2(maximum_desired_capacity,
                                    MetaspaceSize);
    log_trace(gc, metaspace)("    maximum_free_percentage: %6.2f  minimum_used_percentage: %6.2f",
                             maximum_free_percentage, minimum_used_percentage);
    log_trace(gc, metaspace)("    minimum_desired_capacity: %6.1fKB  maximum_desired_capacity: %6.1fKB",
                             minimum_desired_capacity / (double) K, maximum_desired_capacity / (double) K);

    assert(minimum_desired_capacity <= maximum_desired_capacity,
           "sanity check");

    if (capacity_until_GC > maximum_desired_capacity) {
      // Capacity too large, compute shrinking size
      shrink_bytes = capacity_until_GC - maximum_desired_capacity;
      shrink_bytes = shrink_bytes / 100 * current_shrink_factor;

      shrink_bytes = align_down(shrink_bytes, Metaspace::commit_alignment());

      assert(shrink_bytes <= max_shrink_bytes,
             "invalid shrink size " SIZE_FORMAT " not <= " SIZE_FORMAT,
             shrink_bytes, max_shrink_bytes);
      if (current_shrink_factor == 0) {
        _shrink_factor = 10;
      } else {
        _shrink_factor = MIN2(current_shrink_factor * 4, (uint) 100);
      }
      log_trace(gc, metaspace)("    shrinking:  initThreshold: %.1fK  maximum_desired_capacity: %.1fK",
                               MetaspaceSize / (double) K, maximum_desired_capacity / (double) K);
      log_trace(gc, metaspace)("    shrink_bytes: %.1fK  current_shrink_factor: %d  new shrink factor: %d  MinMetaspaceExpansion: %.1fK",
                               shrink_bytes / (double) K, current_shrink_factor, _shrink_factor, MinMetaspaceExpansion / (double) K);
    }
  }

  // Don't shrink unless it's significant
  if (shrink_bytes >= MinMetaspaceExpansion &&
      ((capacity_until_GC - shrink_bytes) >= MetaspaceSize)) {
    size_t new_capacity_until_GC = MetaspaceGC::dec_capacity_until_GC(shrink_bytes);
    Metaspace::tracer()->report_gc_threshold(capacity_until_GC,
                                             new_capacity_until_GC,
                                             MetaspaceGCThresholdUpdater::ComputeNewSize);
  }
}

由场景一可知,为了避免弹性伸缩带来的额外 GC 消耗,我们会将 -XX:MetaSpaceSize-XX:MaxMetaSpaceSize 两个值设置为固定的,但是这样也会导致在空间不够的时候无法扩容,然后频繁地触发 GC,最终 OOM。所以关键原因就是 ClassLoader 不停地在内存中 load 了新的 Class ,一般这种问题都发生在动态类加载等情况上。

4.3.3 策略

了解大概什么原因后,如何定位和解决就很简单了,可以 dump 快照之后通过 JProfiler 或 MAT 观察 Classes 的 Histogram(直方图) 即可,或者直接通过命令即可定位, jcmd 打几次 Histogram 的图,看一下具体是哪个包下的 Class 增加较多就可以定位了。不过有时候也要结合InstBytes、KlassBytes、Bytecodes、MethodAll 等几项指标综合来看下。如下图便是笔者使用 jcmd 排查到一个 Orika 的问题。

jcmd <PID> GC.class_stats|awk '{print$13}'|sed  's/\(.*\)\.\(.*\)/\1/g'|sort |uniq -c|sort -nrk1

如果无法从整体的角度定位,可以添加 -XX:+TraceClassLoading-XX:+TraceClassUnLoading 参数观察详细的类加载和卸载信息。

4.3.4 小结

原理理解比较复杂,但定位和解决问题会比较简单,经常会出问题的几个点有 Orika 的 classMap、JSON 的 ASMSerializer、Groovy 动态加载类等,基本都集中在反射、Javasisit 字节码增强、CGLIB 动态代理、OSGi 自定义类加载器等的技术点上。另外就是及时给 MetaSpace 区的使用率加一个监控,如果指标有波动提前发现并解决问题。

4.4 场景四:过早晋升 *

4.4.1 现象

这种场景主要发生在分代的收集器上面,专业的术语称为“Premature Promotion”。90% 的对象朝生夕死,只有在 Young 区经历过几次 GC 的洗礼后才会晋升到 Old 区,每经历一次 GC 对象的 GC Age 就会增长 1,最大通过 -XX:MaxTenuringThreshold 来控制。

过早晋升一般不会直接影响 GC,总会伴随着浮动垃圾、大对象担保失败等问题,但这些问题不是立刻发生的,我们可以观察以下几种现象来判断是否发生了过早晋升。

分配速率接近于晋升速率,对象晋升年龄较小。

GC 日志中出现“Desired survivor size 107347968 bytes, new threshold 1(max 6)”等信息,说明此时经历过一次 GC 就会放到 Old 区。

Full GC 比较频繁,且经历过一次 GC 之后 Old 区的变化比例非常大

比如说 Old 区触发的回收阈值是 80%,经历过一次 GC 之后下降到了 10%,这就说明 Old 区的 70% 的对象存活时间其实很短,如下图所示,Old 区大小每次 GC 后从 2.1G 回收到 300M,也就是说回收掉了 1.8G 的垃圾,只有 300M 的活跃对象。整个 Heap 目前是 4G,活跃对象只占了不到十分之一。

过早晋升的危害:

  • Young GC 频繁,总的吞吐量下降。
  • Full GC 频繁,可能会有较大停顿。

4.4.2 原因

主要的原因有以下两点:

  • Young/Eden 区过小: 过小的直接后果就是 Eden 被装满的时间变短,本应该回收的对象参与了 GC 并晋升,Young GC 采用的是复制算法,由基础篇我们知道 copying 耗时远大于 mark,也就是 Young GC 耗时本质上就是 copy 的时间(CMS 扫描 Card Table 或 G1 扫描 Remember Set 出问题的情况另说),没来及回收的对象增大了回收的代价,所以 Young GC 时间增加,同时又无法快速释放空间,Young GC 次数也跟着增加。

  • 分配速率过大: 可以观察出问题前后 Mutator 的分配速率,如果有明显波动可以尝试观察网卡流量、存储类中间件慢查询日志等信息,看是否有大量数据被加载到内存中。

同时无法 GC 掉对象还会带来另外一个问题,引发动态年龄计算:JVM 通过 -XX:MaxTenuringThreshold 参数来控制晋升年龄,每经过一次 GC,年龄就会加一,达到最大年龄就可以进入 Old 区,最大值为 15(因为 JVM 中使用 4 个比特来表示对象的年龄)。设定固定的 MaxTenuringThreshold 值作为晋升条件:

  • MaxTenuringThreshold 如果设置得过大,原本应该晋升的对象一直停留在 Survivor 区,直到 Survivor 区溢出,一旦溢出发生,Eden + Survivor 中对象将不再依据年龄全部提升到 Old 区,这样对象老化的机制就失效了。

  • MaxTenuringThreshold 如果设置得过小,过早晋升即对象不能在 Young 区充分被回收,大量短期对象被晋升到 Old 区,Old 区空间迅速增长,引起频繁的 Major GC,分代回收失去了意义,严重影响 GC 性能。

相同应用在不同时间的表现不同,特殊任务的执行或者流量成分的变化,都会导致对象的生命周期分布发生波动,那么固定的阈值设定,因为无法动态适应变化,会造成和上面问题,所以 Hotspot 会使用动态计算的方式来调整晋升的阈值。

具体动态计算可以看一下 Hotspot 源码,具体在 /src/hotspot/share/gc/shared/ageTable.cpp 的 compute_tenuring_threshold 方法中:

uint ageTable::compute_tenuring_threshold(size_t survivor_capacity) {
  //TargetSurvivorRatio默认50,意思是:在回收之后希望survivor区的占用率达到这个比例
  size_t desired_survivor_size = (size_t)((((double) survivor_capacity)*TargetSurvivorRatio)/100);
  size_t total = 0;
  uint age = 1;
  assert(sizes[0] == 0, "no objects with age zero should be recorded");
  while (age < table_size) {//table_size=16
    total += sizes[age];
    //如果加上这个年龄的所有对象的大小之后,占用量>期望的大小,就设置age为新的晋升阈值
    if (total > desired_survivor_size) break;
    age++;
  }

  uint result = age < MaxTenuringThreshold ? age : MaxTenuringThreshold;
  if (PrintTenuringDistribution || UsePerfData) {

    //打印期望的survivor的大小以及新计算出来的阈值,和设置的最大阈值
    if (PrintTenuringDistribution) {
      gclog_or_tty->cr();
      gclog_or_tty->print_cr("Desired survivor size " SIZE_FORMAT " bytes, new threshold %u (max %u)",
        desired_survivor_size*oopSize, result, (int) MaxTenuringThreshold);
    }

    total = 0;
    age = 1;
    while (age < table_size) {
      total += sizes[age];
      if (sizes[age] > 0) {
        if (PrintTenuringDistribution) {
          gclog_or_tty->print_cr("- age %3u: " SIZE_FORMAT_W(10) " bytes, " SIZE_FORMAT_W(10) " total",
                                        age,    sizes[age]*oopSize,          total*oopSize);
        }
      }
      if (UsePerfData) {
        _perf_sizes[age]->set_value(sizes[age]*oopSize);
      }
      age++;
    }
    if (UsePerfData) {
      SharedHeap* sh = SharedHeap::heap();
      CollectorPolicy* policy = sh->collector_policy();
      GCPolicyCounters* gc_counters = policy->counters();
      gc_counters->tenuring_threshold()->set_value(result);
      gc_counters->desired_survivor_size()->set_value(
        desired_survivor_size*oopSize);
    }
  }

  return result;
}

可以看到 Hotspot 遍历所有对象时,从所有年龄为 0 的对象占用的空间开始累加,如果加上年龄等于 n 的所有对象的空间之后,使用 Survivor 区的条件值(TargetSurvivorRatio / 100,TargetSurvivorRatio 默认值为 50)进行判断,若大于这个值则结束循环,将 n 和 MaxTenuringThreshold 比较,若 n 小,则阈值为 n,若 n 大,则只能去设置最大阈值为 MaxTenuringThreshold。动态年龄触发后导致更多的对象进入了 Old 区,造成资源浪费

4.4.3 策略

知道问题原因后我们就有解决的方向,如果是 Young/Eden 区过小,我们可以在总的 Heap 内存不变的情况下适当增大 Young 区,具体怎么增加?一般情况下 Old 的大小应当为活跃对象的 2~3 倍左右,考虑到浮动垃圾问题最好在 3 倍左右,剩下的都可以分给 Young 区。

拿笔者的一次典型过早晋升优化来看,原配置为 Young 1.2G + Old 2.8G,通过观察 CMS GC 的情况找到存活对象大概为 300~400M,于是调整 Old 1.5G 左右,剩下 2.5G 分给 Young 区。仅仅调了一个 Young 区大小参数(-Xmn),整个 JVM 一分钟 Young GC 从 26 次降低到了 11 次,单次时间也没有增加,总的 GC 时间从 1100ms 降低到了 500ms,CMS GC 次数也从 40 分钟左右一次降低到了 7 小时 30 分钟一次。

如果是分配速率过大:

  • 偶发较大:通过内存分析工具找到问题代码,从业务逻辑上做一些优化。

  • 一直较大:当前的 Collector 已经不满足 Mutator 的期望了,这种情况要么扩容 Mutator 的 VM,要么调整 GC 收集器类型或加大空间。

4.4.4 小结

过早晋升问题一般不会特别明显,但日积月累之后可能会爆发一波收集器退化之类的问题,所以我们还是要提前避免掉的,可以看看自己系统里面是否有这些现象,如果比较匹配的话,可以尝试优化一下。一行代码优化的 ROI 还是很高的。

如果在观察 Old 区前后比例变化的过程中,发现可以回收的比例非常小,如从 80% 只回收到了 60%,说明我们大部分对象都是存活的,Old 区的空间可以适当调大些。

4.4.5 加餐

关于在调整 Young 与 Old 的比例时,如何选取具体的 NewRatio 值,这里将问题抽象成为一个蓄水池模型,找到以下关键衡量指标,大家可以根据自己场景进行推算。

  • NewRatio 的值 r 与 va、vp、vyc、voc、rs 等值存在一定函数相关性(rs 越小 r 越大、r 越小 vp 越小,...,之前尝试使用 NN 来辅助建模,但目前还没有完全算出具体的公式,有想法的同学可以在评论区给出你的答案)。

  • 总停顿时间 T 为 Young GC 总时间 Tyc 和 Old GC 总时间 Toc 之和,其中 Tyc 与 vyc 和 vp 相关,Toc 与 voc相关。

  • 忽略掉 GC 时间后,两次 Young GC 的时间间隔要大于 TP9999 时间,这样尽量让对象在 Eden 区就被回收,可以减少很多停顿。

4.5 场景五:CMS Old GC 频繁*

4.5.1 现象

Old 区频繁的做 CMS GC,但是每次耗时不是特别长,整体最大 STW 也在可接受范围内,但由于 GC 太频繁导致吞吐下降比较多。

4.5.2 原因

这种情况比较常见,基本都是一次 Young GC 完成后,负责处理 CMS GC 的一个后台线程 concurrentMarkSweepThread 会不断地轮询,使用 shouldConcurrentCollect() 方法做一次检测,判断是否达到了回收条件。如果达到条件,使用 collect_in_background() 启动一次 Background 模式 GC。轮询的判断是使用 sleepBeforeNextCycle() 方法,间隔周期为 -XX:CMSWaitDuration 决定,默认为2s。

具体代码在: src/hotspot/share/gc/cms/concurrentMarkSweepThread.cpp。

void ConcurrentMarkSweepThread::run_service() {
  assert(this == cmst(), "just checking");

  if (BindCMSThreadToCPU && !os::bind_to_processor(CPUForCMSThread)) {
    log_warning(gc)("Couldn't bind CMS thread to processor " UINTX_FORMAT, CPUForCMSThread);
  }

  while (!should_terminate()) {
    sleepBeforeNextCycle();
    if (should_terminate()) break;
    GCIdMark gc_id_mark;
    GCCause::Cause cause = _collector->_full_gc_requested ?
      _collector->_full_gc_cause : GCCause::_cms_concurrent_mark;
    _collector->collect_in_background(cause);
  }
  verify_ok_to_terminate();
}

void ConcurrentMarkSweepThread::sleepBeforeNextCycle() {
  while (!should_terminate()) {
    if(CMSWaitDuration >= 0) {
      // Wait until the next synchronous GC, a concurrent full gc
      // request or a timeout, whichever is earlier.
      wait_on_cms_lock_for_scavenge(CMSWaitDuration);
    } else {
      // Wait until any cms_lock event or check interval not to call shouldConcurrentCollect permanently
      wait_on_cms_lock(CMSCheckInterval);
    }
    // Check if we should start a CMS collection cycle
    if (_collector->shouldConcurrentCollect()) {
      return;
    }
    // .. collection criterion not yet met, let's go back
    // and wait some more
  }
}

判断是否进行回收的代码在:/src/hotspot/share/gc/cms/concurrentMarkSweepGeneration.cpp。

bool CMSCollector::shouldConcurrentCollect() {
  LogTarget(Trace, gc) log;

  if (_full_gc_requested) {
    log.print("CMSCollector: collect because of explicit  gc request (or GCLocker)");
    return true;
  }

  FreelistLocker x(this);
  // ------------------------------------------------------------------
  // Print out lots of information which affects the initiation of
  // a collection.
  if (log.is_enabled() && stats().valid()) {
    log.print("CMSCollector shouldConcurrentCollect: ");

    LogStream out(log);
    stats().print_on(&out);

    log.print("time_until_cms_gen_full %3.7f", stats().time_until_cms_gen_full());
    log.print("free=" SIZE_FORMAT, _cmsGen->free());
    log.print("contiguous_available=" SIZE_FORMAT, _cmsGen->contiguous_available());
    log.print("promotion_rate=%g", stats().promotion_rate());
    log.print("cms_allocation_rate=%g", stats().cms_allocation_rate());
    log.print("occupancy=%3.7f", _cmsGen->occupancy());
    log.print("initiatingOccupancy=%3.7f", _cmsGen->initiating_occupancy());
    log.print("cms_time_since_begin=%3.7f", stats().cms_time_since_begin());
    log.print("cms_time_since_end=%3.7f", stats().cms_time_since_end());
    log.print("metadata initialized %d", MetaspaceGC::should_concurrent_collect());
  }
  // ------------------------------------------------------------------
  if (!UseCMSInitiatingOccupancyOnly) {
    if (stats().valid()) {
      if (stats().time_until_cms_start() == 0.0) {
        return true;
      }
    } else {
  
      if (_cmsGen->occupancy() >= _bootstrap_occupancy) {
        log.print(" CMSCollector: collect for bootstrapping statistics: occupancy = %f, boot occupancy = %f",
                  _cmsGen->occupancy(), _bootstrap_occupancy);
        return true;
      }
    }
  }

  if (_cmsGen->should_concurrent_collect()) {
    log.print("CMS old gen initiated");
    return true;
  }

  // We start a collection if we believe an incremental collection may fail;
  // this is not likely to be productive in practice because it's probably too
  // late anyway.
  CMSHeap* heap = CMSHeap::heap();
  if (heap->incremental_collection_will_fail(true /* consult_young */)) {
    log.print("CMSCollector: collect because incremental collection will fail ");
    return true;
  }

  if (MetaspaceGC::should_concurrent_collect()) {
    log.print("CMSCollector: collect for metadata allocation ");
    return true;
  }

  // CMSTriggerInterval starts a CMS cycle if enough time has passed.
  if (CMSTriggerInterval >= 0) {
    if (CMSTriggerInterval == 0) {
      // Trigger always
      return true;
    }

    // Check the CMS time since begin (we do not check the stats validity
    // as we want to be able to trigger the first CMS cycle as well)
    if (stats().cms_time_since_begin() >= (CMSTriggerInterval / ((double) MILLIUNITS))) {
      if (stats().valid()) {
        log.print("CMSCollector: collect because of trigger interval (time since last begin %3.7f secs)",
                  stats().cms_time_since_begin());
      } else {
        log.print("CMSCollector: collect because of trigger interval (first collection)");
      }
      return true;
    }
  }

  return false;
}

分析其中逻辑判断是否触发 GC,分为以下几种情况:

  • 触发 CMS GC: 通过调用 _collector->collect_in_background() 进行触发 Background GC 。

    • CMS 默认采用 JVM 运行时的统计数据判断是否需要触发 CMS GC,如果需要根据 -XX:CMSInitiatingOccupancyFraction 的值进行判断,需要设置参数 -XX:+UseCMSInitiatingOccupancyOnly

    • 如果开启了 -XX:UseCMSInitiatingOccupancyOnly 参数,判断当前 Old 区使用率是否大于阈值,则触发 CMS GC,该阈值可以通过参数 -XX:CMSInitiatingOccupancyFraction 进行设置,如果没有设置,默认为 92%。

    • 如果之前的 Young GC 失败过,或者下次 Young 区执行 Young GC 可能失败,这两种情况下都需要触发 CMS GC。

    • CMS 默认不会对 MetaSpace 或 Perm 进行垃圾收集,如果希望对这些区域进行垃圾收集,需要设置参数 -XX:+CMSClassUnloadingEnabled

  • 触发 Full GC: 直接进行 Full GC,这种情况到场景七中展开说明。

    • 如果 _full_gc_requested 为真,说明有明确的需求要进行 GC,比如调用 System.gc。

    • 在 Eden 区为对象或 TLAB 分配内存失败,导致一次 Young GC,在 GenCollectorPolicy 类的 satisfy_failed_allocation() 方法中进行判断。

大家可以看一下源码中的日志打印,通过日志我们就可以比较清楚地知道具体的原因,然后就可以着手分析了。

4.5.3 策略

我们这里还是拿最常见的达到回收比例这个场景来说,与过早晋升不同的是这些对象确实存活了一段时间,Survival Time 超过了 TP9999 时间,但是又达不到长期存活,如各种数据库、网络链接,带有失效时间的缓存等。

处理这种常规内存泄漏问题基本是一个思路,主要步骤如下:

Dump Diff 和 Leak Suspects 比较直观就不介绍了,这里说下其它几个关键点:

  • 内存 Dump: 使用 jmap、arthas 等 dump 堆进行快照时记得摘掉流量,同时分别在 CMS GC 的发生前后分别 dump 一次
  • 分析 Top Component: 要记得按照对象、类、类加载器、包等多个维度观察 Histogram,同时使用 outgoing 和 incoming 分析关联的对象,另外就是 Soft Reference 和 Weak Reference、Finalizer 等也要看一下。
  • 分析 Unreachable: 重点看一下这个,关注下 Shallow 和 Retained 的大小。如下图所示,笔者之前一次 GC 优化,就根据 Unreachable Objects 发现了 Hystrix 的滑动窗口问题。

4.5.4 小结

经过整个流程下来基本就能定位问题了,不过在优化的过程中记得使用控制变量的方法来优化,防止一些会加剧问题的改动被掩盖。

4.6 场景六:单次 CMS Old GC 耗时长*

4.6.1 现象

CMS GC 单次 STW 最大超过 1000ms,不会频繁发生,如下图所示最长达到了 8000ms。某些场景下会引起“雪崩效应”,这种场景非常危险,我们应该尽量避免出现。

4.6.2 原因

CMS 在回收的过程中,STW 的阶段主要是 Init Mark 和 Final Remark 这两个阶段,也是导致 CMS Old GC 最多的原因,另外有些情况就是在 STW 前等待 Mutator 的线程到达 SafePoint 也会导致时间过长,但这种情况较少,我们在此处主要讨论前者。发生收集器退化或者碎片压缩的场景请看场景七。

想要知道这两个阶段为什么会耗时,我们需要先看一下这两个阶段都会干什么。

核心代码都在 /src/hotspot/share/gc/cms/concurrentMarkSweepGeneration.cpp 中,内部有个线程 ConcurrentMarkSweepThread 轮询来校验,Old 区的垃圾回收相关细节被完全封装在 CMSCollector 中,调用入口就是 ConcurrentMarkSweepThread 调用的 CMSCollector::collect_in_backgroundConcurrentMarkSweepGeneration 调用的 CMSCollector::collect 方法,此处我们讨论大多数场景的 collect_in_background。整个过程中会 STW 的主要是 initial Mark 和 Final Remark,核心代码在 VM_CMS_Initial_Mark / VM_CMS_Final_Remark 中,执行时需要将执行权交由 VMThread 来执行。

  • CMS Init Mark执行步骤,实现在 CMSCollector::checkpointRootsInitialWork()CMSParInitialMarkTask::work 中,整体步骤和代码如下:
void CMSCollector::checkpointRootsInitialWork() {
  assert(SafepointSynchronize::is_at_safepoint(), "world should be stopped");
  assert(_collectorState == InitialMarking, "just checking");

  // Already have locks.
  assert_lock_strong(bitMapLock());
  assert(_markBitMap.isAllClear(), "was reset at end of previous cycle");

  // Setup the verification and class unloading state for this
  // CMS collection cycle.
  setup_cms_unloading_and_verification_state();

  GCTraceTime(Trace, gc, phases) ts("checkpointRootsInitialWork", _gc_timer_cm);

  // Reset all the PLAB chunk arrays if necessary.
  if (_survivor_plab_array != NULL && !CMSPLABRecordAlways) {
    reset_survivor_plab_arrays();
  }

  ResourceMark rm;
  HandleMark  hm;

  MarkRefsIntoClosure notOlder(_span, &_markBitMap);
  CMSHeap* heap = CMSHeap::heap();

  verify_work_stacks_empty();
  verify_overflow_empty();

  heap->ensure_parsability(false);  // fill TLABs, but no need to retire them
  // Update the saved marks which may affect the root scans.
  heap->save_marks();

  // weak reference processing has not started yet.
  ref_processor()->set_enqueuing_is_done(false);

  // Need to remember all newly created CLDs,
  // so that we can guarantee that the remark finds them.
  ClassLoaderDataGraph::remember_new_clds(true);

  // Whenever a CLD is found, it will be claimed before proceeding to mark
  // the klasses. The claimed marks need to be cleared before marking starts.
  ClassLoaderDataGraph::clear_claimed_marks();

  print_eden_and_survivor_chunk_arrays();

  {
    if (CMSParallelInitialMarkEnabled) {
      // The parallel version.
      WorkGang* workers = heap->workers();
      assert(workers != NULL, "Need parallel worker threads.");
      uint n_workers = workers->active_workers();

      StrongRootsScope srs(n_workers);

      CMSParInitialMarkTask tsk(this, &srs, n_workers);
      initialize_sequential_subtasks_for_young_gen_rescan(n_workers);
      // If the total workers is greater than 1, then multiple workers
      // may be used at some time and the initialization has been set
      // such that the single threaded path cannot be used.
      if (workers->total_workers() > 1) {
        workers->run_task(&tsk);
      } else {
        tsk.work(0);
      }
    } else {
      // The serial version.
      CLDToOopClosure cld_closure(&notOlder, true);
      heap->rem_set()->prepare_for_younger_refs_iterate(false); // Not parallel.

      StrongRootsScope srs(1);

      heap->cms_process_roots(&srs,
                             true,   // young gen as roots
                             GenCollectedHeap::ScanningOption(roots_scanning_options()),
                             should_unload_classes(),
                             &notOlder,
                             &cld_closure);
    }
  }

  // Clear mod-union table; it will be dirtied in the prologue of
  // CMS generation per each young generation collection.
  assert(_modUnionTable.isAllClear(),
       "Was cleared in most recent final checkpoint phase"
       " or no bits are set in the gc_prologue before the start of the next "
       "subsequent marking phase.");

  assert(_ct->cld_rem_set()->mod_union_is_clear(), "Must be");
  // Save the end of the used_region of the constituent generations
  // to be used to limit the extent of sweep in each generation.
  save_sweep_limits();
  verify_overflow_empty();
}
void CMSParInitialMarkTask::work(uint worker_id) {
  elapsedTimer _timer;
  ResourceMark rm;
  HandleMark   hm;

  // ---------- scan from roots --------------
  _timer.start();
  CMSHeap* heap = CMSHeap::heap();
  ParMarkRefsIntoClosure par_mri_cl(_collector->_span, &(_collector->_markBitMap));

  // ---------- young gen roots --------------
  {
    work_on_young_gen_roots(&par_mri_cl);
    _timer.stop();
    log_trace(gc, task)("Finished young gen initial mark scan work in %dth thread: %3.3f sec", worker_id, _timer.seconds());
  }

  // ---------- remaining roots --------------
  _timer.reset();
  _timer.start();

  CLDToOopClosure cld_closure(&par_mri_cl, true);

  heap->cms_process_roots(_strong_roots_scope,
                          false,     // yg was scanned above
                          GenCollectedHeap::ScanningOption(_collector->CMSCollector::roots_scanning_options()),
                          _collector->should_unload_classes(),
                          &par_mri_cl,
                          &cld_closure,
                          &_par_state_string);

  assert(_collector->should_unload_classes()
         || (_collector->CMSCollector::roots_scanning_options() & GenCollectedHeap::SO_AllCodeCache),
         "if we didn't scan the code cache, we have to be ready to drop nmethods with expired weak oops");
  _timer.stop();
  log_trace(gc, task)("Finished remaining root initial mark scan work in %dth thread: %3.3f sec", worker_id, _timer.seconds());
}

整个过程比较简单,从 GC Root 出发标记 Old 中的对象,处理完成后借助 BitMap 处理下 Young 区对 Old 区的引用,整个过程基本都比较快,很少会有较大的停顿。

  • CMS Final Remark 执行步骤,实现在 CMSCollector::checkpointRootsFinalWork() 中,整体代码和步骤如下:
void CMSCollector::checkpointRootsFinalWork() {
  GCTraceTime(Trace, gc, phases) tm("checkpointRootsFinalWork", _gc_timer_cm);

  assert(haveFreelistLocks(), "must have free list locks");
  assert_lock_strong(bitMapLock());

  ResourceMark rm;
  HandleMark   hm;

  CMSHeap* heap = CMSHeap::heap();

  if (should_unload_classes()) {
    CodeCache::gc_prologue();
  }
  assert(haveFreelistLocks(), "must have free list locks");
  assert_lock_strong(bitMapLock());

  heap->ensure_parsability(false);  // fill TLAB's, but no need to retire them
  // Update the saved marks which may affect the root scans.
  heap->save_marks();

  print_eden_and_survivor_chunk_arrays();

  {
    if (CMSParallelRemarkEnabled) {
      GCTraceTime(Debug, gc, phases) t("Rescan (parallel)", _gc_timer_cm);
      do_remark_parallel();
    } else {
      GCTraceTime(Debug, gc, phases) t("Rescan (non-parallel)", _gc_timer_cm);
      do_remark_non_parallel();
    }
  }
  verify_work_stacks_empty();
  verify_overflow_empty();

  {
    GCTraceTime(Trace, gc, phases) ts("refProcessingWork", _gc_timer_cm);
    refProcessingWork();
  }
  verify_work_stacks_empty();
  verify_overflow_empty();

  if (should_unload_classes()) {
    CodeCache::gc_epilogue();
  }
  JvmtiExport::gc_epilogue();
  assert(_markStack.isEmpty(), "No grey objects");
  size_t ser_ovflw = _ser_pmc_remark_ovflw + _ser_pmc_preclean_ovflw +
                     _ser_kac_ovflw        + _ser_kac_preclean_ovflw;
  if (ser_ovflw > 0) {
    log_trace(gc)("Marking stack overflow (benign) (pmc_pc=" SIZE_FORMAT ", pmc_rm=" SIZE_FORMAT ", kac=" SIZE_FORMAT ", kac_preclean=" SIZE_FORMAT ")",
                         _ser_pmc_preclean_ovflw, _ser_pmc_remark_ovflw, _ser_kac_ovflw, _ser_kac_preclean_ovflw);
    _markStack.expand();
    _ser_pmc_remark_ovflw = 0;
    _ser_pmc_preclean_ovflw = 0;
    _ser_kac_preclean_ovflw = 0;
    _ser_kac_ovflw = 0;
  }
  if (_par_pmc_remark_ovflw > 0 || _par_kac_ovflw > 0) {
     log_trace(gc)("Work queue overflow (benign) (pmc_rm=" SIZE_FORMAT ", kac=" SIZE_FORMAT ")",
                          _par_pmc_remark_ovflw, _par_kac_ovflw);
     _par_pmc_remark_ovflw = 0;
    _par_kac_ovflw = 0;
  }
   if (_markStack._hit_limit > 0) {
     log_trace(gc)(" (benign) Hit max stack size limit (" SIZE_FORMAT ")",
                          _markStack._hit_limit);
   }
   if (_markStack._failed_double > 0) {
     log_trace(gc)(" (benign) Failed stack doubling (" SIZE_FORMAT "), current capacity " SIZE_FORMAT,
                          _markStack._failed_double, _markStack.capacity());
   }
  _markStack._hit_limit = 0;
  _markStack._failed_double = 0;

  if ((VerifyAfterGC || VerifyDuringGC) &&
      CMSHeap::heap()->total_collections() >= VerifyGCStartAt) {
    verify_after_remark();
  }

  _gc_tracer_cm->report_object_count_after_gc(&_is_alive_closure);

  // Change under the freelistLocks.
  _collectorState = Sweeping;
  // Call isAllClear() under bitMapLock
  assert(_modUnionTable.isAllClear(),
      "Should be clear by end of the final marking");
  assert(_ct->cld_rem_set()->mod_union_is_clear(),
      "Should be clear by end of the final marking");
}

Final Remark 是最终的第二次标记,这种情况只有在 Background GC 执行了 InitialMarking 步骤的情形下才会执行,如果是 Foreground GC 执行的 InitialMarking 步骤则不需要再次执行 FinalRemark。Final Remark 的开始阶段与 Init Mark 处理的流程相同,但是后续多了 Card Table 遍历、Reference 实例的清理并将其加入到 Reference 维护的 pend_list 中,如果要收集元数据信息,还要清理 SystemDictionary、CodeCache、SymbolTable、StringTable 等组件中不再使用的资源。

4.6.3 策略

知道了两个 STW 过程执行流程,我们分析解决就比较简单了,由于大部分问题都出在 Final Remark 过程,这里我们也拿这个场景来举例,主要步骤:

  • 【方向】 观察详细 GC 日志,找到出问题时 Final Remark 日志,分析下 Reference 处理和元数据处理 real 耗时是否正常,详细信息需要通过 -XX:+PrintReferenceGC 参数开启。基本在日志里面就能定位到大概是哪个方向出了问题,耗时超过 10% 的就需要关注
2019-02-27T19:55:37.920+0800: 516952.915: [GC (CMS Final Remark) 516952.915: [ParNew516952.939: [SoftReference, 0 refs, 0.0003857 secs]516952.939: [WeakReference, 1362 refs, 0.0002415 secs]516952.940: [FinalReference, 146 refs, 0.0001233 secs]516952.940: [PhantomReference, 0 refs, 57 refs, 0.0002369 secs]516952.940: [JNI Weak Reference, 0.0000662 secs]
[class unloading, 0.1770490 secs]516953.329: [scrub symbol table, 0.0442567 secs]516953.373: [scrub string table, 0.0036072 secs][1 CMS-remark: 1638504K(2048000K)] 1667558K(4352000K), 0.5269311 secs] [Times: user=1.20 sys=0.03, real=0.53 secs]
  • 【根因】 有了具体的方向我们就可以进行深入的分析,一般来说最容易出问题的地方就是 Reference 中的 FinalReference 和元数据信息处理中的 scrub symbol table 两个阶段,想要找到具体问题代码就需要内存分析工具 MAT 或 JProfiler 了,注意要 dump 即将开始 CMS GC 的堆。在用 MAT 等工具前也可以先用命令行看下对象 Histogram,有可能直接就能定位问题。

    • 对 FinalReference 的分析主要观察 java.lang.ref.Finalizer 对象的 dominator tree,找到泄漏的来源。经常会出现问题的几个点有 Socket 的 SocksSocketImpl 、Jersey 的 ClientRuntime、MySQL 的 ConnectionImpl 等等。

    • scrub symbol table 表示清理元数据符号引用耗时,符号引用是 Java 代码被编译成字节码时,方法在 JVM 中的表现形式,生命周期一般与 Class 一致,当 _should_unload_classes 被设置为 true 时在 CMSCollector::refProcessingWork() 中与 Class Unload、String Table 一起被处理。

if (should_unload_classes()) {
    {
      GCTraceTime(Debug, gc, phases) t("Class Unloading", _gc_timer_cm);

      // Unload classes and purge the SystemDictionary.
      bool purged_class = SystemDictionary::do_unloading(_gc_timer_cm);

      // Unload nmethods.
      CodeCache::do_unloading(&_is_alive_closure, purged_class);

      // Prune dead klasses from subklass/sibling/implementor lists.
      Klass::clean_weak_klass_links(purged_class);
    }

    {
      GCTraceTime(Debug, gc, phases) t("Scrub Symbol Table", _gc_timer_cm);
      // Clean up unreferenced symbols in symbol table.
      SymbolTable::unlink();
    }

    {
      GCTraceTime(Debug, gc, phases) t("Scrub String Table", _gc_timer_cm);
      // Delete entries for dead interned strings.
      StringTable::unlink(&_is_alive_closure);
    }
  }
  • 【策略】 知道 GC 耗时的根因就比较好处理了,这种问题不会大面积同时爆发,不过有很多时候单台 STW 的时间会比较长,如果业务影响比较大,及时摘掉流量,具体后续优化策略如下:

    • FinalReference:找到内存来源后通过优化代码的方式来解决,如果短时间无法定位可以增加 -XX:+ParallelRefProcEnabled 对 Reference 进行并行处理。

    • symbol table:观察 MetaSpace 区的历史使用峰值,以及每次 GC 前后的回收情况,一般没有使用动态类加载或者 DSL 处理等,MetaSpace 的使用率上不会有什么变化,这种情况可以通过 -XX:-CMSClassUnloadingEnabled 来避免 MetaSpace 的处理,JDK8 会默认开启 CMSClassUnloadingEnabled,这会使得 CMS 在 CMS-Remark 阶段尝试进行类的卸载。

4.6.4 小结

正常情况进行的 Background CMS GC,出现问题基本都集中在 Reference 和 Class 等元数据处理上,在 Reference 类的问题处理方面,不管是 FinalReference,还是 SoftReference、WeakReference 核心的手段就是找准时机 dump 快照,然后用内存分析工具来分析。Class 处理方面目前除了关闭类卸载开关,没有太好的方法。

在 G1 中同样有 Reference 的问题,可以观察日志中的 Ref Proc,处理方法与 CMS 类似。

阅读更多:

Java中9种常见的CMS GC问题分析与解决(下)

7. 参考资料

8. 作者简介

  • 新宇:2015 年加入美团,到店住宿门票业务开发工程师。
  • 湘铭:2018 年加入美团,到店客户平台开发工程师。
  • 祥璞:2018 年加入美团,到店客户平台开发工程师。

9. 招聘信息

美团到店事业群住宿门票数据智能组诚招小伙伴,从供、控、选、售等层面全方位提升业务竞争力,十万级 QPS 处理,亿级数据分析,完整业务闭环,目前有海量 HC,有兴趣的请将邮件发送至 hezhiming@meituan.com,我们会在第一时间与你联系。

想阅读更多技术文章,请关注美团技术团队(meituantech)官方微信公众号。