Jvm-内存泄漏排查

最新推荐文章于 2024-04-12 23:58:44 发布

朝露白

最新推荐文章于 2024-04-12 23:58:44 发布

阅读量587

点赞数 2

分类专栏： Java 文章标签： Jvm

本文链接：https://blog.csdn.net/qq_28091033/article/details/100775917

版权

Java 专栏收录该内容

1 篇文章 0 订阅

订阅专栏

一、背景

最近线上有个用mina编写的同步程序，作为服务端，用来接收客户端发送来的数据。一个月前程序突然宕机，运维人员联系了我，当时没发现原因，查看了脚本中配置的jvm参数为：-Xmx4096m -Xms1024m，由于每天接收的数据量还是比较大的，这样配置堆最小值和最大值也是没问题的。最后只能在堆中加溢出参数，等待下次溢出时再分析原因了。修改后的参数如下：

-Xmx4096m -Xms1024m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/d5000/eas/easDmSync/heapdump.hprof

果然上周程序又宕机了，生成的dump文件将近4g，说明堆已经扩容到最大了。不过此刻即开心又难受，这么大的dump文件，公司是内网开发，只能靠jdk下的原生工具分析，能读dump的工具也只有jvisualvm了。好呗，就搞一下呗！

看到了吧，byte数组竟然是number one！难道是程序中的流没关闭？由于接收发送端的数据要经过BaseCode64进行处理了下，会产生Byte数组，于是检查代码并进行流关闭、byte[]用完赋值null等操作。同时检查了Mina会不会像netty一样存在内存泄漏，发现客户端发的是字符串，服务端不会有buffer产生，应该没有类似netty中的泄漏。

最后重新打包代码，再次修改Jvm参数和启动参数，通过Jconsole远程连接到程序，观察老年代的内存情况，合适的时候手动导出dump文件。启动参数配置如下：

nohup java 
-Xmx4096m -Xms1536m -XX:NewRatio=1:2 -XX:SurvivorRatio=1:2 
-Djava.rmi.server.hostname=192.168.129.129 -Dcom.sun.management.jmxremote
-Dcom.sun.management.jmxremote.port=9090 
-Dcom.sun.management.jmxremote.authenticate=false 
-Dcom.sun.management.jmxremote.ssl=false -jar  easDmsync.jar &

二、监测

由于数据量比较大，并且手头比较忙，所以将堆配置的大了点。(如果堆设置小一点的话，老年代采采样会很快的)，这样算起来老年代大小为1g左右。运行三天后的老年代如下：

从上面的两个图可以看到，整个堆的走向是由老年代决定的。6号到8号期间老年代最大内存基本为1g，说明堆没有扩容，但看每次回收后的值发现，老年代的可用空间越来越小，到9号就进行了整个堆的扩容。这说明程序问题不是出在BaseCode64那边，也不是mina。那奇怪了，代码中没有地方用字节数组了啊！！真是日了……。

三、探索

1.工具jhat

看来需要使用一个可以查看内存分布的工具，手头真特么的穷，只有用最原始的jhat了操作一波了。

在jdk的bin目录下执行jhat命令，-J-Xmx5096m指定jhat的最大堆空间，这个需要配大点！

执行N分钟后，会开启7000端口的服务。

访问http://localhost:7000/histo/

从上面看到字节数组[B实例有16072277个，大小有690多兆。由于程序中没有直接使用内存数组，它到底来自哪呢？点击超链接 class [B ，看看里面有没有什么可疑线索。

上面选中第一个字节数组，再点进去。

懵逼了，怎么又跑到二维字节数组里了。好吧，尝试点reachable吧！

从上往下看，是不是更懵逼！怎么来自某个Map中。路断了。。

只有再回到开头了。

咦！上面有个认识的类 class dm.jdbc.driver.DmdbPreparedStatement_bs(Dm7JdbcDriver17.jar下的) ，实例数也不小呢。

点进去

上面有字节数组，莫非……

再向下看

乖乖！它属于某个拥有40万元素的集合中，难道是PreparedStatement使用了没关闭吗？再次检查代码，对所有的PreparedStatement在finally中关闭。打包在次发布！运行了一段时间，发现堆的内存走向和上面没有区别！！！

2.神器Mat

经过上面的折腾，问题不但没有解决，感觉整个人都傻了。最后只能向领导申请，允许我把dump文件拷到外网分析！最后找到了内存分析神器mat。

使用mat打开hprof文件，界面如下：

kao！上来一个大饼！多直观！

不用说了，占了1.1g的肯定是和字节数组有关的。

接着下面给了判语:

猜想存在问题的部分竟然是BasicResourcePool，内存占了1个过G。

想起来一年前同是用C3p0经常出现宕机问题，莫非是C3P0引起的？

点击detail后如下图

从下向上是gc root的路线，最后问题还是定位到BasicResourcePool这里。

继续向下拖，再看看Accumulated Objects in Dominator Tree

BasicResourcePool中有很多NewPooledConnection，这应该是C3P0缓存的Connection对象了。看Retained Heap这列可以发现每个Connection都占了不少内存，里面究竟缓存了什么？

从上图中选择一个Connection，点击Java Basics -Open In Dominator Tree

打开的是NewPooledConnection的内部引用结构，从下面图可以看到NewPooledConnection中有DmdbConnection，DmdbConnection中有Vector，发现了没？这个集合Vector占了不少内存，而其中元素为DmdbPreparedStatement_bs。奇怪了！在之前我已完全关闭了所有的PreparedStatement了啊。只能翻翻源码了……

点中上图中框中的类，点击Merge shortest Paths To GC Root,查看gc root 路线，对着变量名字去翻Dm7JdbcDriver17驱动的源码。

先找那个Vector集合的名字，对应上图中的stmtsVec，类型为Vector集合，去DmdbConnection_bs类中搜这个集合

  private Vector<Statement> stmtsVec = null;
  
  public synchronized PreparedStatement prepareStatement(String sql, int resultSetType, int resultSetConcurrency, int resultSetHoldability)throws SQLException{
    DmdbPreparedStatement_bs pstmt = null;
    //……省略部分
    //从集合Map<String, DmdbPreparedStatement_bs> preparedStmtPool中获取
    pstmt = getFromPreparedStmtPool(sql);
    if (pstmt != null){
        //……
    }
    else{
      pstmt = new DmdbPreparedStatement_bs(this, sql, resultSetType,            
         resultSetConcurrency, resultSetHoldability);
    }
    //注意这里，每创建一个DmdbPreparedStatement_bs都放进stmtsVec中
    addStmt(pstmt);
    return pstmt;
  }

  private void addStmt(Statement stmt){
    this.stmtsVec.add(stmt);
  }

从上面代码可以发现，每创建一个PreparedStatement 都会缓存到stmtsVec集合中。那现在关心的是什么时候移除stmtsVec里面的元素呢？总共有两个地方：

第一个地方是DmdbConnection_bs(Connection实现类)下面的close方法(如下图)，当直接调用Connection的close方法的时候会清空stmtsVec，但C3P0不会真正关闭Connection，所以不会调用这个close方法，自然不会清空stmtsVec。

public synchronized void close() throws SQLException {
 if (this.closed) {
      return;
 }
 close_statements();
 if (this.svptStmt != null){
     this.svptStmt.innerClose();
     this.svptStmt = null;
 }
 this.stmtsVec.clear();
}

第二处是DmdbConnection_bs中的delStmt方法：

 public void delStmt(Statement stmt){
    if ((this.stmtsVec == null) || (this.stmtsVec.isEmpty())) {
      return;
    }
    this.stmtsVec.remove(stmt);//会从集合中移除statement
  }

而delStmt方法是在DmdbPreparedStatement_bs父类里的下的innerClose方法调用的。也就是说当我们调用PreparedStatement的close方法时会调用delStmt方法。DmdbPreparedStatement_bs下的close方法如下：

public synchronized void close()throws SQLException {
    //……省略部分
    if(connection !=null && !connection.closed && realClose &&         
      connection.getStmtPoolMaxSize()>0){//Connection不关闭，就符合条件
       closed=true;
       connection.remove_statement(handle);//释放句柄
       connection.addToPreparedStmtPool(this);//添加到缓存
    }else{//我们的程序没有走else里
      innerClose();
      return;
   }
}

public synchronized void innerClose()throws SQLException{
    try
    {
      super.innerClose();
    }
    catch (SQLException e){
      throw e;
    }
    finally{
      //……省略
    }
  }

//父类DmdbStatment_bs
public synchronized void innerClose()throws SQLException
  {
    try
    {
      if ((this.connection != null) && (!this.connection.closed)){
        DmdbCSI.freeHandle(this);
        this.connection.remove_statement(this.handle);

        this.connection.delStmt(this);//这里会把自身从stmtsVec中删除
      }
    }
    finally
    {
     //……省略
    }
  }

在之前我们所有的PreparedStatement都已经手动关闭，但为什么没从stmtsVec删掉呢？原因是我们的程序没有进入close方法里的else，也就是说没有调用innerClose，自然没有调用delStmt。走到这里一切真相浮出水面。。。

至此得出结论：

正常情况下调用Connection的close方法时svpStmt会被清空的，但C3p0由于缓存了Connection，当我们调用关闭的时候并没有真正的关闭Connection，当然Vector里的数据不会被清空，同时手动关闭PreparedStatement也不会移除元素，结果PreparedStatement累积越来越多，最后导致内存溢出。

3.溢出验证

虽然结论出来了，但说Dm7JdbcDriver17.jar有问题似乎没有说服力，下面给出验证。

根据上面Merge shortest Paths To GC Root出来的图，通过反射一步步获取对象及里面的属性，监控stmtsVec集合是否真的膨胀了。由于内网环境，代码无法拷出来，拍了照，贴在下面。

上面一大段代码看着比较多，都是根据上面图一步反射来的，其中主要看printDM16方法中最后一句，这里会一分钟统计一次stmtsVec集合中PreparedStatement的个数，经过测试发现，有的Connection中，PreparedStatement的个数都达到10几万，即使触发垃圾回收，依旧个数递增。如下图：

后来把Dm7JdbcDriver17.jar驱动包换成Dm7JdbcDriver16.jar，重新打包发布，运行监测发现Connection关闭的时候对应的stmtsVec会被清空。日志如下：

四、最终结果

下面图是运行了三天的结果，参数还是之前的参数，老年代最大1G左右内存，呈现规律的锯齿波，基本一天回收一次，还是很合理的。堆内存整体趋势也很规整，图形上的毛刺是一次次Young GC，由于很多对象都是朝夕生死的，加上数据量很大，回收频繁是很正常的(但三天回收了8000多次，有点多，参数需要进一步调整)。具体图和参数见下面的图

五、调优

1.调优方法

讲Jvm调优的书很多，但都没有明确的给出调优的基本标准，这是因为场景不一样，调优的标准也就不一样。其实只要不存在内存泄漏以及明显的Old Gc卡顿，使用基本的参数或者默认参数就可以了，没必要浪费太多时间去调优(学习还是要花时间的)。个人浅薄的总结一下方法：

1) 老年代回收是否频繁

2) 老年代可用内存是否放逐渐缩小，最后导致堆扩容

3) 出现内存问题了可以直接用mat分析、Jconsole都很直接了当(尽量不要使用Jhat，很吃内存，不直观、浪费时间)

4) 如果是linux服务器并且本地可以远程到服务的话，可以配置如下的启动参数，使用远程的方式。

-Djava.rmi.server.hostname=192.168.129.129 -Dcom.sun.management.jmxremote
-Dcom.sun.management.jmxremote.port=9090 
-Dcom.sun.management.jmxremote.authenticate=false 
-Dcom.sun.management.jmxremote.ssl=false

5) 如果方法4不行的话，最基本的就靠指令了，如jmap、jstat、jstack等了，也可以导出dump文件，用mat分析。这是最坏的情况。

2.常用命令

1.jmap

jmap -histo pid 查看实例个数和内存大小，linux环境很好用

jmap -F -dump:live,file=jmap.hprof pid 导出内存dump文件，之后可以用mat分析

2.jstat

jstat -gc pid 5000 定时查看新、老容量和使用情况

jstat -gcutil pid 和上面差不多

3.jstack

配合top使用，可以先查看消耗cpu多进程 top -p pid -H

jstack pid 查看线程状态，如死锁检测

4.常用参数

启动程序时配置内存溢出时自动导出dump文件

-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/d5000/eas/easDmSync/heapdump.hprof

本地eclipse远程调试参数

-agentlib:jdwp=transport=dt_socket,adress=1080,server=y,suspend=n

朝露白

关注

2
点赞
踩
0

收藏

觉得还不错? 一键收藏
0
评论
复制链接

分享到 QQ

分享到新浪微博

扫一扫

专栏目录