转载

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

今天发现线上一个应用内存占用非常高,但它的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 实例的状态

记一次&quot;内存泄露&quot;排查过程

这里可以看到这个 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
    used
    free
    使用率为 1.6%
    
  • PS Old Generation : 老年代堆的使用情况

    capacity
    used
    free
    使用率为 5.7%
    

为什么空闲了这么多内存没有被释放,发生了什么。等等,还有两个重要参数没有讲

  • Heap Configuration : 堆的配置信息
    MinHeapFreeRatio
    MaxHeapFreeRatio
    

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,所以没用的实例都被释放了。

原文  https://juejin.im/post/5da579bf6fb9a04e143dbd3c
正文到此结束
Loading...