“堆内存持续占用高 且 ygc 回收效果不佳” 排查处理实践

作者：京东零售　王江波

说明：部分素材来源于网络，数据分析全为真实数据。

一、 问题背景

自建的两套工具，运行一段时间后均出现 内存占用高触发报警，频繁 young gc 且效果不佳。曾经尝试多次解决，因各种原因耽搁，最近下定决心处理此问题。

二、 问题描述

Q：堆内存 1018M，使用达到 950M 左右触发一次 young gc，ygc 之后内存占用 630M，未发生 full gc

三、 容器配置

已处理关键信息

•主机名 xxx

•实例 ID xxx

•ip

•操作系统名称 Linux

•操作系统体系结构 amd64

•CPU 个数 2

•JRE 版本 1.8.0_191

•JVM 启动时间 2023-02-18 17:14:10.873

•启动路径/export/App

•Full GCPS MarkSweep

•Young GCPS Scavenge

•进程 ID115135

•物理内存大小 251.4GB(269888389120Byte)

•交换区大小 0.0GB(0Byte)

•虚拟内存大小 12.5GB(13368197120Byte)

•应用路径/export/App/lib/tp-center-web.jar!/BOOT-INF/lib/

•JVM 启动参数-javaagent:/export/xxx/lib/pfinder-profiler-agent-1.0.8-20210322032622-6f12bda2.jar -Ddeploy.app.name=xxx -Ddeploy.app.id=xxx -Ddeploy.instance.id=0 -Ddeploy.instance.name=server1 -DJDOS_DATACENTER=HT -Dloader.path=./conf -Dspring.profiles.active=pre -Xms1024m -Xmx1024m -Xmn384m -XX:MetaspaceSize=64m -XX:CMSInitiatingOccupancyFraction=70 -XX:+UseCMSInitiatingOccupancyOnly -XX:ParallelGCThreads=2 -XX:CICompilerCount=2 -XX:MaxDirectMemorySize=128m -Duser.timezone=Asia/Shanghai -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=xxx -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Djava.rmi.server.hostname=xxx

四、 问题分析

1、 young gc 的时机？

R：ygc 在新生代的 eden 区满了之后就会触发，采用复制算法回收新生代的垃圾。

2、 为何 young gc 后堆内存使用率仍然很高？

R：新生代过小，大对象直接进入老年代，编码时要尽量减少大对象的使用。

3、 full gc 的时机？

R：HotSpot VM 里，除了 CMS 之外，其它能收集老年代的 GC 都会同时收集整个 GC 堆，包括新生代

1） 发生 fgc 之前进行检查，如果 老年代可用的连续内存空间 < 新生代历次 ygc 后升入老年代的对象总和的平均大小，此时先触发 old gc，然后执行 ygc

2） 执行 ygc 之后有一批对象需要放入老年代，此时老年代没有足够空间存放对象，必须触发一次 ogc

3） 老年代内存使用率超过阈值，也要触发 ogc

4） 元空间不足时也会触发一次

4、 什么原因导致内存占用高？

R：heap dump 分析、gc 日志

五、 回收器

•吞吐量优先（Parallel Scavenge）：新生代收集器，侧重于吞吐量（吞吐量=运行用户代码时间/(运行用户代码时间+运行垃圾收集时间)）的控制。

•Serial Old：Serial Old 是 Serial 收集器的老年代版本， 它同样是一个单线程收集器， 使用标记-整理算法：由于老年代 Serial Old 收集器在服务端应用性能上的“拖累”, 使用 Parallel Scavenge 收集器也未必能在整体上获得吞吐量最大化的效果。由于单线程的老年代收集中无法充分利用服务器多处理器的并行处理能力, 在老年代内存空间很大而且硬件规格比较高级的运行环境中, 这种组合的总吞吐量甚至不一定比 ParNew 加 CMS 的组合来得优秀。

•Parallel Old ：是 Parallel Scavenge 收集器的老年代版本, 支持多线程并发收集, 基于标记-整理算法实现. 这个收集器是直到 JDK 6 时才开始提供的, 在此之前, 新生代的 Parallel Scavenge 收集器一直处于相当尴尬的状态, 原因是如果新生代选择了 Parallel Scavenge 收集器, 老年代除了 Serial Old(PS MarkSweep)收集器以外别无选择

UseParallelGC: JDK9 之前虚拟机运行在 Server 模式下的默认值, 使用 ParallelScavenge + Serial Old(PS MarkSweep)的收集器组合进行内存回收。

UseParallelOldGC: 打开此开关后, 使用 Parallel Scavenge + Parallel Old 的收集器组合进行内存回收。

•ParNew 收集器与 Parallel 收集器类似：此收集器是许多运行在 Server 模式下的虚拟机的首选，除了 Serial 收集器外，只有它能与 CMS 收集器配合工作

•并发标记清除（CMS）回收器：是一种以获取最短回收停顿时间为目标的回收器，该回收器是基于“标记-清除”算法实现的。注重回收时产生的停顿时间，是停顿时间最短的收集器。非常适合注重用户体验的应用上，是 Hotspot 虚拟机第一款真正意义上的并发收集器，第一次实现了让垃圾收集线程与用户线程几乎同时运行

六、 优化策略

1、 加 gc 日志

-XX:+PrintGCDetails // 创建详细的 gc 日志

-XX:+PrintGCTimeStamps

-Xloggc:/export/Logs/com/gc.log // gc 日志文件名

-XX:+UseGCLogFileRotation // 限制保存在 gc 日志中的数据量

-XX:GCLogFileSize=10M // 日志文件大小

-XX:NumberOfGCLogFiles=10 // 日志文件个数

-XX:+HeapDumpAfterFullGC // fullgc 前 dump 文件保存

-XX:HeapDumpPath=/export/Logs/com/fgcdump.log // dump 文件保存路径

-XX:+HeapDumpOnOutOfMemoryError

-XX:HeapDumpPath=目录 // oom 时生成 dump 文件

// ================================= 附加参数如下 =============================================

// 可以使用-XX:DisableExplicitGC 选项禁用显示调用 Full gc（system.gc 在 cms gc 下我们通过-XX:+ExplicitGCInvokesConcurrent 来做一次稍微高效点的 GC(效果比 Full GC 要好些)）

-XX:+UnlockExperimentalVMOptions // 解锁实验参数，允许使用实验性参数，JVM 中有些参数不能通过-XX 直接复制需要先解锁，比如要使用某些参数的时候，可能不会生效，需要设置这个参数来解锁 -XX:+UseParNewGC // 真正的并发收集器，与 CMS 搭配使用（ParNew 收集器是 Serial 收集器的多线程版本，使用这个参数后会在新生代进行并行回收，老年代仍旧使用串行回收。新生代 S 区任然使用复制算法） -XX:+UseConcMarkSweepGC // 和应用程序线程一起执行，相对于 Stop The World 来说虚拟机停顿时间较少。停顿减少，吞吐量会降低。它使用的是 标记清除算法，运作过程为四个步骤，分别是 初始标记—并发标识—重新标记—并发清除。它是老年代的收集算法，新生代使用 ParNew 收集算法。默认关闭

CMS 收集器的缺点是对服务器 CPU 资源较为敏感，在并发标记时会降低吞吐量。它使用的标记清除算法也会产生大量空间碎片，空间碎片的存在会加大 Full GC 的频率，虽然老年代还有足够的内存，但是因为内存空间不连续，不得不进行 Full GC -XX:CMSInitiatingOccupancyFraction=75 // 允许最大占用占用率 -XX:+UseCMSInitiatingOccupancyOnly // 只用设定的回收阈值,如果不指定,JVM 仅在第一次使用设定值,后续则自动调整 -XX:+ExplicitGCInvokesConcurrent // ExplicitGCInvokesConcurrent 这个参数是配合 CMS 使用的，开启后 System.gc()还是会触发 Full GC，不过并不是一个完全的 stop-the-world 的 Full GC，而是并发的 CMS GC -XX:+ParallelRefProcEnabled // 可以用来并行处理 Reference，以加快处理速度，缩短耗时 -XX:+CMSParallelRemarkEnabled // 在 CMS GC 前启动一次 ygc，目的在于减少 old gen 对 ygc gen 的引用，降低 remark 时的开销-----一般 CMS 的 GC 耗时 80%都在 remark 阶段

// 切记以下参数不要乱加

-XX:+UseCMSCompactAtFullCollection // Full GC 后，进行一次整理，整理过程是独占的，会引起停顿时间变长。仅在使用 CMS 收集器时生效。

-XX:CMSFullGCsBeforeCompaction // 默认为 0，就是每次 FullGC 都对老年代进行碎片整理压缩，建议保持默认

2、 gc 日志指标

S0: 新生代中 Survivor space 0 区已使用空间的百分比

S1: 新生代中 Survivor space 1 区已使用空间的百分比 E: 新生代已使用空间的百分比 O: 老年代已使用空间的百分比 M: 元空间已使用空间的百分比

CCS: 压缩类空间利用率百分比 YGC: 从应用程序启动到当前，发生 Yang GC 的次数

YGCT: 从应用程序启动到当前，Yang GC 所用的时间【单位秒】 FGC: 从应用程序启动到当前，发生 Full GC 的次数 FGCT: 从应用程序启动到当前，Full GC 所用的时间 GCT: 从应用程序启动到当前，用于垃圾回收的总时间【单位秒】

3、 最大线程数

系统可创建最大线程数 = （机器本身可用内存 - JVM 分配的堆内存 - JVM 元数据区）/ 线程栈大小

4、 内存分析

4.1 常用命令

4.1.1 jstack

// Java 堆栈跟踪工具，它用于打印出给定的 java 进程 ID、core file、远程调试服务的 Java 堆栈信息.

jstack 命令用于生成虚拟机当前时刻的线程快照线程快照是当前虚拟机内每一条线程正在执行的方法堆栈的集合，使用其主要目的是定位线程出现长时间停顿的原因，如线程间死锁、死循环、请求外部资源导致长时间等待等问题线程出现停顿的时候通过 jstack 来查看线程的调用堆栈，就可以知道没有响应的线程到底在做什么事，或者等待什么资源若 java 程序崩溃生成 core 文件，jstack 可用来获得 core 文件的 java stack 和 native stack 的信息

还可附属到正在运行的 java 程序上，看到当前运行的 java 程序的 java stack 和 native stack 信息，若呈现 hung 状态，jstack 很有用

应用：jstack [option] <pid> // 打印某个进程的堆栈信息

•线程状态

•Monitor 监视锁

item1：实战案例 1 jstack 分析死锁问题

死锁指的是两个或两个以上的线程在执行过程中，因争夺资源而造成的一种互相等待的现象，若无外力作用，将无法继续进行

jps：终端中输入 jsp 查看当前运行的 java 程序

8896

5684 JUnitStarter

17836 Jps

19804 Launcher

文件分析：【本文件未死锁，仅用于分析，死锁时会出现 线程 1 持有 A 等 B，线程 2 持有 B 等 A】

"consumer_monitor_report_tp_pre_1_1_3_1677132947525" #7851 daemon prio=5 os_prio=0 tid=0x00007f8d2001b000 nid=0x31c8c waiting on condition [0x00007f8ceeeef000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000fad6df60> (a java.util.concurrent.CountDownLatch$Sync) ... Locked ownable synchronizers: - None

// consumer_monitor_report_tp_pre_1_1_3_1677132947525 的线程处于 TIMED_WAITING 状态，持有 - None 锁（无锁），等待 0x00000000fad6df60 的锁

item2：实战案例 2 jstack 分析 cp 过高问题

•通过 top 命令查看各个进程 cpu 使用情况，默认按 cpu 使用率高到低排序

•通过 top -Hp pid 查看该进程下，各个线程的 cpu 使用情况

•定位到 cpu 占用率高的线程之后，使用 jstack pid 命令查看当前 java 进程的堆栈状态

•nid=0x31c8b 进制转换，文件中，每个线程都有一个 nid，查看状态

4.1.2 jstat

// java 虚拟机统计信息工具，利用 JVM 内建的指令对 Java 应用程序的资源和性能进行实时的命令行的监控

远程监控：jstat -gcutil port@ip

说明：GCT = YGCT + FGCT

4.1.3 jmap-histo

// 查看堆内存中的对象数目、大小统计直方图，如果带上 live 则只统计活对象

包括对 Heap size 和 垃圾回收状况的监控

num #instances #bytes class name ---------------------------------------------- 1: 3153872 297505208 [C 2: 214428 113791808 [B 3: 88856 81288672 [I 4: 3123084 74954016 java.lang.String 5: 520601 20824040 java.util.LinkedHashMap$Entry6:26877915051624java.util.zip.Deflater7:10598114981000[Ljava.lang.Object;8:3888349332016java.util.zip.ZStreamRef9:12247197248[J10:179735855104[Ljava.util.HashMap$Node; 11: 177935 5693920 java.util.HashMap$Node12:1696785429696org.elasticsearch.common.bytes.BytesArray13:1109005323200java.util.zip.Inflater14:543144779632java.lang.reflect.Method15:423363725568org.elasticsearch.search.SearchHit16:1271123050688org.elasticsearch.common.text.Text17:833582667456java.util.concurrent.ConcurrentHashMap$Node 18: 21894 2416424 java.lang.Class 19: 42925 2060400 java.util.HashMap 20: 55340 1770880 java.io.ObjectStreamClass$WeakClassKey

4.1.4 jmqp-heap

// 查看进程堆内存使用情况，包括使用的 GC 算法、堆配置参数和各代中堆内存使用情况

using thread-local object allocation. Parallel GC with 2 thread(s)

Heap Configuration: MinHeapFreeRatio = 0 MaxHeapFreeRatio = 100 MaxHeapSize = 1073741824 (1024.0MB) NewSize = 402653184 (384.0MB) MaxNewSize = 402653184 (384.0MB) OldSize = 671088640 (640.0MB) NewRatio = 2 SurvivorRatio = 8 MetaspaceSize = 67108864 (64.0MB) CompressedClassSpaceSize = 1073741824 (1024.0MB) MaxMetaspaceSize = 17592186044415 MB G1HeapRegionSize = 0 (0.0MB)

Heap Usage: PS Young Generation Eden Space: capacity = 393216000 (375.0MB) used = 381729360 (364.0454864501953MB) free = 11486640 (10.954513549804688MB) 97.07879638671875% used From Space: capacity = 4718592 (4.5MB) used = 3489328 (3.3276824951171875MB) free = 1229264 (1.1723175048828125MB) 73.94849989149306% used To Space: capacity = 4718592 (4.5MB) used = 0 (0.0MB) free = 4718592 (4.5MB) 0.0% used PS Old Generation capacity = 671088640 (640.0MB) used = 633681304 (604.3255844116211MB) free = 37407336 (35.674415588378906MB) 94.4258725643158% used

49351 interned Strings occupying 4857128 bytes.

4.1.5 jmqp-dump

// 生成堆快照（瞬时）

利用 jvisualvm 分析内存 dump 文件：点击文件->装入->文件类型选“堆”

Visual VM 的 OQL 语言是对 HeapDump 进行查询，类似于 SQL 的查询语言，它的基本语法如下：

select <JavaScript expression to select> [ from [instanceof] <class name> <identifier> [ where <JavaScript boolean expression to filter> ] ]

OQL 由 3 个部分组成：select 子句、from 子句和 where 子句。select 子句指定查询结果要显示的内容。from 子句指定查询范围，可指定类名，如 java.lang.String、char[]、[Ljava.io.File;（File 数组）。where 子句用于指定查询条件。

4.2 加日志后

见调优方案

七、 调优方案 1：增大新生代

1、 解析 gc 日志

元空间分配 64M（不足自动调整了），新生代改为 480m

•25.939: [Full GC (Metadata GC Threshold) [PSYoungGen: 4133K->0K(461312K)] [ParOldGen: 34773K->36327K(557056K)] 38907K->36327K(1018368K), [Metaspace: 62967K->62967K(1105920K)], 0.3564880 secs] [Times: user=0.72 sys=0.02, real=0.36 secs]

八、 调优方案 2：增大元空间 + CMS & PNEW

以下方案暂时没啥问题

九、 临时方案以观后效

说明：去批量处理，降低对象大小，也许也是一个不错的方案，待验证。

-Xms1024m -Xmx1024m -Xmn480m -Xss512k -XX:MetaspaceSize=128m -XX:ParallelGCThreads=2 -XX:CICompilerCount=2 -XX:MaxDirectMemorySize=256m -XX:+UnlockExperimentalVMOptions -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly -XX:+ExplicitGCInvokesConcurrent -XX:+ParallelRefProcEnabled -XX:+CMSParallelRemarkEnabled -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:/export/Logs/xxx/gc.log -XX:GCLogFileSize=100M -XX:+HeapDumpAfterFullGC -XX:HeapDumpPath=/export/Logs/xxx/fgcdump.log

部署稳定后 jvm 监控图表如下：