记一次"内存泄露"排查过程
问题的发现
今天发现线上一个应用内存占用非常高,但它的cpu使用率却很低
使用ps
命令,可以看到 进程 19793 占用了4.9G的内存,然而它cpu使用率还不到5%,有问题。
# ps -aux | grep 19793
user 19793 1.6 9.9 23864228 4904664 ? Sl Oct03 268:52
我判断这个应用应该是发生了内存泄露,开始进行问题定位和排查。
内存泄露的排查过程一般如下:
- 使用 jmap 查看哪些对象个数非常多,内存占用多
- 分析 dump 文件和堆占用情况
- 定位具体的类和相关代码的调用过程,一步一步的查找问题所在
工具的使用和介绍这里不赘述了,引用一个博主的文章
问题定位与排查
1. 使用 jmap 查看堆的使用情况
运行命令 jmap -hive 19793
查看对象实例的情况,如图:
这里发现 StandardSession
实例竟然有140万个。StandardSession
是tomcat的Session的具体实现,难道说Tomcat发生了内存泄露了。
2. 了解Tomcat Session的实现和回收原理
Tomcat 使用 StandardManager
管理服务的Session,而 StandardSession
存储了每个Session对象的数据。
StandardManager
会定期检测每个Session
实例是否过期,如果过期,则进行回收处理。
这里直接看源码,了解 Tomcat 如何 管理 Session 的
// 具体的检测代码在父类 ManagerBase 中
public StandardManager extends ManagerBase {
// ... 忽略不必要的代码
}
public abstract class ManagerBase extends LifecycleMBeanBase implements Manager {
//Session实例都是保存在这个Map中的,key 值是 sessionId
protected Map<String, Session> sessions = new ConcurrentHashMap<>();
// 定时运行函数,Tomcat 有一个守护线程,会定时的遍历运行每个容器的 backgroundProcess 函数,
// 一般需要定时执行的代码,都会实现这个函数,让Tomcat统一调用,这样也方便管理
public void backgroundProcess() {
count = (count + 1) % processExpiresFrequency;
if (count == 0)
processExpires();
}
public void processExpires() {
//记录当前时间
long timeNow = System.currentTimeMillis();
Session sessions[] = findSessions();
int expireHere = 0 ;
//遍历所有session,查看是否过期
for (int i = 0; i < sessions.length; i++) {
//判断session是否过期,这里可以看出实际判断是否过期的实现在 session 类中
if ( sessions[i]!=null && !sessions[i].isValid() ) {
expireHere++;
}
}
long timeEnd = System.currentTimeMillis();
processingTime += ( timeEnd - timeNow );}
}
这里看看StandardSession的代码
// 看看StandardSession 怎么判断 session 是否过期的
public class StandardSession implements HttpSession, Session, Serializable {
//最后活跃时间
protected volatile long lastAccessedTime = creationTime;
// 过期时间,-1 为用不过期
protected volatile int maxInactiveInterval = -1;
// 记录该实例是否已做过期处理
protected volatile boolean isValid = false;
@Override
public boolean isValid() {
//判断是否已经做过期处理
if (!this.isValid) {
return false;
}
//这里开始判断session是否有过期
if (maxInactiveInterval > 0) {
//getIdleTimeInternal 函数是计算最后一次使用时间到当前的间隔
int timeIdle = (int) (getIdleTimeInternal() / 1000L);
//如果时间间隔大于过期时间,进行清除处理
//具体的清除就不贴了,简单的说就是执行 manager 的 sessions.remove(obj) 操作,并且做一下其他的处理
if (timeIdle >= maxInactiveInterval) {
expire(true);
}
}
return this.isValid;
}
}
通过上述的 manager
和 Session
代码,可以清晰的知道 Session 过期处理逻辑,那么是哪里出现了问题,导致 Session 对象没有被回收。
3. 看看自己的代码是否有问题
一般来说对象没有被回收,一定是在某个地方被引用了,这里看看我代码中是怎么用的。实际上我只有在一个拦截器中使用了 session 的操作。
我项目中应用了 session 的代码
// 这是拦截器的一个函数,每个请求进来,必须经过拦截器处理,如果某些方面验证错误,则直接返回错误信息给客户端
public boolean preHandle(HttpServletRequest request, Object handler) throws IOException {
// 获取该请求的 Session对象
HttpSession httpSession = request.getSession();
// 获取请求的参数,并操作 httpSession
// 这里 setMaxInactiveInterval 表示设置该session的过期时间,1800s
String sessionUin = (String) httpSession.getAttribute("uin");
httpSession.setAttribute("uin", uin);
httpSession.setMaxInactiveInterval(1800);
// 其他处理逻辑 ...
return true;
}
讲道理,我的代码使用是不可能引起内存泄露的,难道我遇到了Tomcat的bug,想想有点兴奋,继续找原因吧。
4. 导出线上进程的堆栈信息,查看StandardSession实例的值
导出进程的堆栈信息:jmap -dump:format=b,file=tomcatDump 19793
利用 jhat
看看 StandardSession 实例的状态
这里可以看到这个 StandardSession 的 isValid = false
,说明该实例进行过缓存过期处理,
看看它最后一次被访问的时间 lastAccessedTime: 1570329063605
,将时间戳转换一下,时间为 2019-10-06 10:31:03:605
,而当前时间为2019-10-13
,这早就过期了呀,怎么回事呢。
这好像不太对劲啊,在网上看看有没有其他人遇到过同样的问题。使用谷歌搜索,根本没有发现有这样情况的人。
我都打算另寻他法了,发现还真的有人跟我遇到一样的问题了。但是仔细一看,原来是tomcat6的bug,tomcat的开发人员让他升级到tomcat7就可以了。而项目用的是tomcat9,这个问题早就修复了。
5. 再次查看项目的堆栈使用情况
第二天,我还是有点不死心,话说问题没解决怎么能行。
查看项目中实例的数量
> jmap -hive 19793
num #instances #bytes class name
----------------------------------------------
1: 37494 76896680 [I
2: 25378 20727448 [B
3: 171462 19284664 [C
4: 141175 3388200 java.lang.String
5: 561 2513408 [Ljava.util.concurrent.ConcurrentHashMap$Node;
6: 77525 2480800 java.util.HashMap$Node
7: 38859 2247400 [Ljava.lang.Object;
8: 20021 1761848 java.lang.reflect.Method
9: 14842 1651912 java.lang.Class
10: 51005 1632160 java.util.concurrent.ConcurrentHashMap$Node
11: 18588 1567464 [Ljava.util.HashMap$Node;
12: 29526 1181040 java.util.LinkedHashMap$Entry
13: 13645 764120 java.util.LinkedHashMap
14: 36894 763928 [Ljava.lang.Class;
15: 22800 729600 com.mysql.cj.conf.BooleanProperty
16: 14720 706560 java.util.HashMap
17: 37818 605088 java.lang.Object
18: 18016 432384 java.util.ArrayList
纳尼,我的140万个 StandardSession 实例呢,怎么全没了。看看应用的内存占用,还是一样啊,占了差不多5GB的空间,不对劲。
看看堆栈使用情况
> jmap -heap 19793
using thread-local object allocation.
Parallel GC with 18 thread(s)
Heap Configuration:
MinHeapFreeRatio = 0
MaxHeapFreeRatio = 100
//...省略部分不必要的东西
Heap Usage:
PS Young Generation
Eden Space:
capacity = 3287285760 (3135.0MB)
used = 53116712 (50.656044006347656MB)
free = 3234169048 (3084.3439559936523MB)
1.6158227753220944% used
//...省略部分不必要的东西
PS Old Generation
capacity = 1083703296 (1033.5MB)
used = 62036632 (59.162742614746094MB)
free = 1021666664 (974.3372573852539MB)
5.724503397653226% used
分析下这些信息:
-
Eden Space
: 新生代堆的使用情况-
capacity
:总大小,当前堆的大小为 3.1GB -
used
: 已使用的空间, 当前已使用 50MB -
free
: 空闲的空间 当前空闲了3.08GB 使用率为 1.6%
-
-
PS Old Generation
: 老年代堆的使用情况-
capacity
:总大小,当前堆的大小为 1 GB -
used
: 已使用的空间, 当前已使用 59 MB -
free
: 空闲的空间 当前空闲了 974 MB 使用率为 5.7%
-
为什么空闲了这么多内存没有被释放,发生了什么。等等,还有两个重要参数没有讲
-
Heap Configuration
: 堆的配置信息-
MinHeapFreeRatio
: 堆空间最小空闲比例 ,如果堆的空闲比例小于这个值,JVM将进行扩容处理 -
MaxHeapFreeRatio
: 堆空间最大空闲比例, 如果堆的空闲比例超过这个值,JVM将压缩堆空间
-
6. 问题定位及解决方法
到这就知道问题所在了,堆的最大空闲比例为100,表示当堆的使用率为0%时,才会对堆内存做压缩,这永远不会对堆内存进行压缩处理嘛,坑爹呢。
当JVM进行垃圾回收的时候,将不必要的实例清除了,但是由于配置的原因,导致空间不会被压缩,所以该应用一直占用很多空间,而且还越用越大。
解决方法就是在运行的时候在运行的时候加上 -XXMinHeapFreeRatio=10 -XX:MaxHeapFreeRatio=60
。
7. 一点小拓展
这里拓展一下项目中两种Java堆的配置。
- 稳定的Java堆
-Xms 和 -Xmx 相等,JVM一开始就分配最大的堆内存,如此一来就不需要在运行的时候频繁的扩充堆的内存
这个在高吞吐量的项目中是非常实用的。不需要频繁的扩充堆,也不需要频繁的进行垃圾回收处理,可以减少垃圾回收的次数和总时间。
-Xms 和 -Xmx 相等时
,MinHeapFreeRatio 和 MaxHeapFreeRatio 的配置将无效。(这都不需要动态扩展堆大小了,就算配置也用不上)
- 动荡的Java堆
如果不做处理JVM默认会配置该模式,即 -Xms初始是一个比较小的值,在系统运行时需要更大的堆空间,才会去扩展堆的大小,直到 -Xms 等于 -Xmx
总结
到此,这次的“内存泄露”事件就结束了,其实也不是内存泄露。
一开始问题定位错了,还以为是Tomcat的原因,还特意的去了解Tomcat 的 Session 管理机制和代码实现。还好后来发现了问题所在,没有在错误的方向浪费太多时间,不然把Tomcat的源码翻一遍也找不到具体原因。
补充一点,为什么140万个StandardSession实例已经做过期处理了,但是没有释放呢,这是因为系统内存还较为充足,而且这些实例经过多次 minorGC 都转移到了年老代(项目的Session的有效期为5个小时),如果不进行一次FullGC,是不会整理年老代的数据的。第二天发现实例被清除,这是因为我运行了 jmap -dump 命令,这个会强制的让JVM执行一次FullGC,所以没用的实例都被释放了。
参考文章:
下一篇: C语言推箱子小游戏分析