频繁FullGC的原因竟然是 “开源代码”？

2023-07-28 17:07

来源 | OSCHINA 社区

作者 | 京东云开发者-京东科技郭银利

原文链接：https://my.oschina.net/u/4090830/blog/10090621

前言

首先 java 语言的特性是不需像 C 和 C++ 那样自己手动释放内存，因为 java 本身有垃圾回收机制（垃圾回收称为 GC），顾名思义就是释放垃圾占用的空间，防止内存泄露。JVM 运行时占用内存最大的空间就是堆内存，另外栈区和方法区也会占用空间但是占用有限本章就不探究了。那么堆中的空间又分为年轻代和老年代，所以我们粗略的把垃圾回收分为两种：年轻代的垃圾回收称为 Young GC，老年代的垃圾回收称为 Full GC，实际上此处的 Full GC 也包含了新生代，老年代，元空间等的回收。

因为 Full GC 的回收过程会使系统的所有线程 STW（Stop The World），那么我们一定希望让系统尽量不要进行 Full GC，或者必须要进行 FullGC 的时候执行的时间越短越好。下面我们主要探究 Full GC 的角度出发分析我在开发运营后台的时候遇到的频繁 Full GC 过程。

事件背景

项目介绍：

我们团队做的是一个后台管理系统，因为针对不同用户负责的功能不同那么需要的权限也就不一样，所以引入了主流的 shiro 框架做权限控制，该框架可以控制菜单栏，按钮，操作框等。在引入这个框架时一并引入了辅助组件 shiro-redis，该组件是一个缓存层方便管理用户登录信息，内存泄漏的问题也是就现在这个辅助组件上。

事件还原：

在周五的中午 11:30 分收到了监控的报警信息提示系统在频繁 Full GC，此时我们立刻做两件事情：

第一：登录公司的 UMP 监控平台（开源监控可以参考：【Prometheus+grafana 监控】）查看该机器的系统指标，发现确实在频繁 FullGC 从 11 点持续到了 11 点半

第二：保留一台机器作为证据收集，其他机器进行重启保障业务能正常访问，重启后 full gc 正常

第三：堆栈信息操作指令 ./jmap -F -dump:live,format=b,file=/jmapfile.hprof 18362 （-F 操作是强制导出堆栈信息，18362 是应用 pid，通过 top -c 指令获取）

第四：因为个人无权限导出堆栈信息，马上电话联系运维通过上面指令导出该机器上的堆栈文件，就是抓取现场证据，因为过了这个时间堆内存可能就正常了

根据 JVM 知识分析，常见 Full GC 时的五种情况如下：

1. 老年代内存不足（大对象过多或内存泄漏）
2. Metaspace 空间不足
3. 代码主动触发 System.gc()
4. YGC 时的悲观策略
5. dump live 的内存信息时，比如 jmap -dump:live

分析原因

1、查看公司 SGM 监控平台（开源监控可以参考：【Prometheus+grafana 监控】），元空间最大内存 256M，FullGC 发生前后为 117M，排除 Metaspace 不足造成的原因

2、在系统中搜索第三方 jar 包，没有主动执行 System.gc () 操作的代码

3、查看 JVM 启动参数中有下面两个参数，所以排除了 YGC 时候的悲观策略原因

-XX:CMSInitiatingOccupancyFraction=70      # 堆内存达到 70%进行 FullGC
-XX:+UseCMSInitiatingOccupancyOnly         # 禁止 YGC 时的悲观策略（YGC 前后判断是否需要 FullGC），只有达到阈值才进行 FullGc

4、通过和运维、研发组沟通没有人主动执行 dump 操作，查看系统的历史执行指令也没有 dump 操作，主动 dump 的原因排除

初步分析结果：

通过上面依靠监控平台、JVM 启动参数、代码排除、指令分析，最终嫌疑最大的就是老年代内存空间不足造成频繁 Full GC，但是作为技术者，排除法显然不能作为原因定位的依据，我们还需要继续确定我们的猜想，下面会结合 JVM 启动参数，Tomcat 启动参数，堆栈文件三大关键要素做具体分析。

下图是进行 FullGC 时候的老年代内存情况，把下面的 72%、1794Mb、2496Mb、448Mb 先记住，下面会跟这些值做对比

指标信息：

JVM 核心参数：

-Xms2048M 								# 系统启动初始化堆空间
-Xmx4096M 								# 系统最大堆空间
-Xmn1600M 								# 年轻代空间（包括 From 区和 To），From 和 To 默认占年轻代 20%
-XX:MaxPermSize=256M 					# 最大非堆内存，按需分配
-XX:MetaspaceSize=256M 					# 元空间大小，JDK1.8 取消了永久代（PermGen）新增元空间，元空间并不在虚拟机中，而是使用本地内存。因此，默认情况下，元空间的大小仅受本地内存限制，存储类和类加载器的元数据信息
-XX:CMSInitiatingOccupancyFraction=70 	# 堆内存达到 70%进行 FullGC
-XX:+UseCMSInitiatingOccupancyOnly 		# 禁止 YGC 时的悲观策略（YGC 前后判断是否需要 FullGC），只有达到阈值才进行 FullGc
-XX:+UseConcMarkSweepGC 				# 使用 CMS 作为垃圾收集器

Tomcat 核心参数：

maxThreads=750		# Tomcat 线程池最多能起的线程数
minSpareThreads=50	# Tomcat 初始化的线程池大小或者说 Tomcat 线程池最少会有这么多线程
acceptCount=1000	# Tomcat 维护最大的队列数

通过上边的指标信息我们能对系统的性能瓶颈有大致了解，首先根据 JVM 参数分析结果如下：

堆最大空间 4096M

年轻代占用空间 1600M（包括 Eden 区 1280M，Survivor From160M，Survivor To160M）

老年代最大占用空间 2496M（跟上面的 2496Mb 对应）

系统初始化堆内存 2048M

那么老年代初始内存 (448M) （跟上面的 448Mb 对应）= 初始化堆内存 (2048M) - 年轻代内存 (1600M)

根据 JVM 启动参数确定堆内存达到 70 时进行垃圾回收，系统进行垃圾回收时堆内存占比 72%（跟上面的 72% 对应）一直大于 70%，那么使用内存是 0.72 * 2496Mb ≈ 1794Mb（跟上面的 1794Mb 对应）

堆栈分析：

在查询堆栈前执行 GC 原因指令：jstat -gccause [pid] 1000，执行结果如下图，可以看到 LGCC 这一列代表了最后执行 gc 的原因。CMS Initial Mark 和 CMS Final Remark 这两个阶段是 CMS 垃圾回收的初始标记和最终标记阶段是耗时最长也是造成 STW（Stop The World）的两个阶段

导出堆栈指令：jmap -dump:live,format=b,file=jmapfile.hprof [pid]。导出的文件需要使用 MAT 软件分析，全称 MemoryAnalyzer，主要分析堆内存。参考下载链接：http://eclipse.org/mat/downloads.php

从堆栈文件分析结果中发现有 50 个 org.apache.tomcat.util.threads.TaskThread 占用空间很大。共占用空间 96.16%

每个 TaskThread 实例占用空间 36M 左右

查看内存详情保存最大最多的对象是 ThreadLocal 中存储的 SessionInMemory 对象

最终原因：

通过分析上面的 JVM 参数、Tomcat 参数、堆栈文件，内存泄漏的原因是每个线程中有一个 ThreadLocal 存储大量 SessionInMemory，因为 Tomcat 的启动核心线程数是 50 个，每个线程的内存占用 36M 左右，共占用 1.8G，老年代内存达到 70% 也就是 2496 * 0.7 = 1747.2M 就会进行垃圾回收，1.8G 刚好比 1747.2M 稍微大一些。但是线程中的对象又没办法被回收，所以就会看到系统再频繁 FullGC。

定位问题

通过上面内存分析已经定位到内存泄漏的原因是每个线程中有大量 SessionInMemory，下面步骤就认真分析代码找到其中创建如此多对象还不销毁的原因。

经过初步分析发现 SessionInMemory 是引用 shiro-redis 的工具包里面的对象，主要封装 Session 信息和创建时间。主要作用是在当前线程的 jvm 中做一层缓存当系统频繁获取 Session 时不用去 redis 获取了。SessionInMemary 对象是 shiro 判断用户登录成功时候存储的数据，主要包括用户信息，认证信息，权限信息等，因为用户登录成功后不会重复认证，shiro 会对不同用户做权限判断

分析代码发现处理本地缓存 Session 的流程有明显问题，我画了一个简易的流程图，在介绍流程图前我先描述一下 Session 和用户登录操作如何联系起来

我们都知道运营后台需要用户登录，登录成功后会生成一个 cookie 保存到浏览器中，cookie 存储一个关键字段 sessionId 用来标识用户的状态和信息，当用户访问页面调用接口的时候 shiro 会从请求 Request 中获取 cookie 中的 sessionId，根据这个唯一标识生成 Session 来存储用户的登录态和登录信息等，这些信息会保存到 redis 中。shiro-redis 组件负责从 redis 中获取的 Session 信息通过 ThreadLoca 做到线程隔离。

上图流程概括就是：用户访问页面先从本地缓存获取 Session，如果存在且没有超过一秒就返回结果，如果没有 Session 或者过期了就把现在的 Session 删除并新建一个返回结果。整体看思路清晰，先获取 Session，如果没有就新建返回，如果过期了就删除再新建返回。

流程图隐藏的问题（核心问题）

1、多个线程会复制多份相同 Session 使内存成倍增加（Session 一样线程不同）

举个例子：用户登录后台生成一个 Session，假设请求都到一台机器上，第一次请求到线程 1，第二个请求到线程 2，因为 Session 一样但是线程之间是隔离的，所以线程 1 和线程 2 都会创建一份相同 Session 存储到 ThreaLocal 中，Tomcat 最小空闲线程数越多复制的 Session 份数也越多。因为 Tomcat 的核心线程数不会关闭，所以里面的资源也不会释放。此处有个疑问 ThreadLocad 的 key 是弱引用但是为什么没回收呢？下面统统解答

2、旧 Session 无法清除（线程一样 Session 不同）

举个例子 1：假设所有请求都到一台机器的同一个线程，用户第一次登录后台生成 Session1，第一次请求到线程 1，1 秒内所有请求都执行完了，此时 Session 没有移除（因为 Session 移除策略是懒删除，需要等下次同一个 Session 访问时判断过期条件再删除），用户重新登录，生成了 Session2，因为 Session2 在线程 1 中还没有就会重新创建，导致第一次登录时候用到的 Session1 就一直保存到该线程中了

举个例子 2：参考例子 1 的思路，如果用户用 Session1 没有在 1 秒内把所有请求执行完，就会执行懒删除操作，但是删除后又新建了一个，那么用户重新登录后刚才新建的那个 Session 还是没有被删除，所以总结出来只要用户重新登录必定有一个旧的 Session 会保留到线程中

代码分析

1、在 RedisSessionDAO.java 文件中定义了一个 ThreadLocal 变量作为线程隔离

2、用户访问接口、js 文件、css 文件等资源的时候会进入 shiro 的拦截机制。在拦截过程中会频繁调用 doReasSession () 方法获取用户的 Session 信息，主要是获取信息校验用户的权限控制等。

下面的方法主要整合了获取 Session 操作和设置 Session 操作，如果从 ThreadLocal 中没有获取到或者本地缓存超过 1 秒了就返回 null，判断为 null 之后就会从 redis 中获取并新建一个 Session 存储到 ThreadLoca 中

3、从 ThreadLocal 中取出 sessionMap，根据 sessionId 在 sessionMap 中寻找 Session，如果没找到直接返回 null，如果找到了再判断时间是否超过了 1 秒，如果没超过返回 Session，如果超过了移除返回 null

4、从 ThreadLocal 中获取 sessionMap，如果为 null 就新建一个保存起来，因为用户第一次访问的时候线程中的 sessionMap 还没有呢所以要新建。然后向 sessionMap 中存储 Session 对象

所以代码的完成流程总结：获取 Session 的操作是调用 getSessionFromThreadLocal () 方法，如果没有获取到 Session 就返回 null，调用 setSessionToThreadLocal () 方法会重新设置一个 Session。如果 Session 在当前线程的保存时间超过 1 秒就 remove。

通过上面分析 JVM、Tomat、堆栈、代码已经把问题定位了，因为 shiro-redis 中存储的 SessionInMemory 对象处理不当导致线程间存储越来越多，最终使内存泄漏进而导致了频繁 FullGC。因为我们引用的 shiro-redis 版本是 3.2.2 版本，所以存在这个漏洞，作者已于 2019 年 3 月升级 jar 包到 3.2.3 版本把该问题解决。备注：3.2.2 及以下版本存在该问题

解决问题

解决问题的方案目前有四种。针对我们系统使用的是方案 1 + 方案 4

序号	方案描述	优点	缺点
方案 1	每次设置 session 时遍历删除以前过期或者为 null 的 session	主动删除，删除频次依赖用户的访问频次	如果在 1 秒内有大量用户访问，总 session 很多无效 session 很少，遍历所有 session 做了很多无用功导致访问变慢
方案 2	取消 threadLocal 策略，所有请求直接查询缓存（redis）	减少本地内存使用	访问缓存耗时比本地长，经过测试发现一个接口会调用 16 次左右的获取 session 操作，一个页面几十个接口，直接查询缓存性能存在问题
方案 3	使用本地缓存（guavaCache 或者 EhCache 等），并对缓存做移除策略	多个线程共用一份内存，节省内存空间，提升系统性能	对框架有深入了解，接入需要开发成本
方案 4	把 tomcat 的核心线程数减小，比如把原来的 50 改成 5	减少系统资源，减少相同 Session 的复制份数，大于 5 的线程销毁资源也一起回收	处理并发能力略低

疑问解答

Q：在 RedisSessionDAO 里面只定义了一个 ThreadLocal 的变量 sessionsInThread，怎么就会是 50 个线程把相同的 Session 复制 50 份呢？

A：首先我们先理解 ThreadLocal 的结构，ThreadLocal 有一个静态类 ThreadLocalMap，ThreadLocalMap 里面还有一个 Entry，我们的 key 和 value 就是保存在 Entry 的，key 是一个弱引用的 ThreadLocal 类型，，这个 key 在所有的线程中都是一样的，实际上就是我们定义的静态 sessionsInThread。那又是怎么做到线程隔离的呢？

这就讲到 Thread 中的一个成员变量 threadLocals，这个对象就是 ThreadLocal.ThreadLocalMap 类型，也就是每次创建一个线程都会 new 一个 ThreadLocalMap，所以每个线程中的 ThreadLocalMap 都是不同的，但是里面 Entry 存储的 key 都是一样的，也就是我们前面定义的 sessionsInThread 静态变量。

当一个线程需要获取 Entry 中存储的 value 时候，调用 sessionsInThread.get () 方法，这个方法做了三件事情，一是获取当前线程的实例，二是从线程实例中获取 ThreadLocalMap，三是从 ThreadLocalMap 中根据 ThreadLocal 这个 key 获取指定的 value

获取 Thread 中的 ThreadLocalMap

从 ThreadLocalMap 中获取指定的 value，又有个疑问，获取 Entry 为什么还要从一个 table 数组中拿呢？这个很好理解一个线程不一定只有一个 ThreadLocal 变量吧，多个 ThreadLocal 变量就是有多个 key，所以就放到 table 数组里面了

Q：都说 ThreadLocal 的 key 是一个弱引用，如果内存不足了会被垃圾回收，咱们的 key 从堆栈看并没有回收呀？

A：这是个好问题，首先我们的 RedisSessionDAO 是 Spring 注入的单例模式，ThreadLocal 被定义成一个静态变量，静态变量在内存中是不会回收的。补充：一般我们在使用 ThreadLocal 的时候都会定义成静态变量，如果定义成非静态变量创建一个对象就会 new 一个 ThreadLocal，那么 ThreadLocal 就没有存在的意义了。

Q：已经结束的线程，为什么还会存活，里面的对象也不会消失？

A：因为设置的最小空闲线程数是 50，业务量不大并发数没有超过 50，tomcat 会保留最小的线程数量不会新建也不用回收，ThreadLocalMap 是线程中的成员变量所以不会回收

Q：访问一次接口就会生成一个 sessionId 吗？

A：访问接口先判断用户信息是否有效，无效才会重新登录获取新的 sessionId

Q：shiro-redis 在本地保存 Session 为什么设置 1 秒过期时间？

A：因为运营后台不同于业务接口会持续调用，后台接口大部分的场景是用户访问一个页面并停留在页面上做一些操作，访问一个页面的时候浏览器会加载多个资源，包括静态资源 html，css，js 等，和接口的动态数据，整个资源加载过程尽量保持在一秒内完成，如果超过一秒的话系统体验性能较差，所以本地缓存一秒足够了。