欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识!
您现在的位置是: 首页

记一次"内存泄露"排查过程

程序员文章站 2024-03-19 09:04:22
...

问题的发现

今天发现线上一个应用内存占用非常高,但它的cpu使用率却很低

使用ps命令,可以看到 进程 19793 占用了4.9G的内存,然而它cpu使用率还不到5%,有问题。

# ps -aux | grep 19793
user     19793  1.6  9.9 23864228 4904664 ?    Sl   Oct03 268:52 

我判断这个应用应该是发生了内存泄露,开始进行问题定位和排查。

内存泄露的排查过程一般如下:

  1. 使用 jmap 查看哪些对象个数非常多,内存占用多
  2. 分析 dump 文件和堆占用情况
  3. 定位具体的类和相关代码的调用过程,一步一步的查找问题所在

工具的使用和介绍这里不赘述了,引用一个博主的文章

问题定位与排查

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;
   }
}

通过上述的 managerSession 代码,可以清晰的知道 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,所以没用的实例都被释放了。

参考文章: