72

记一次 OOM 查询过程

 5 years ago
source link: https://mp.weixin.qq.com/s/mEZomoy0RNyL_80L-GsFyg?amp%3Butm_medium=referral
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.

现象

监控系统发现服务挂掉

登上机器  ps -ef|grep ** 发现进程还在,因为监控系统是通过心跳检测来监控服务的存活状态的,服务假死了。

排查过程

1、df、free、top 三连

磁盘空间正常、内存使用率正常、某个进程的CPU占用率达300%多

2、top -H-p pid

查看占用CPU最高的进程对应线程,得到线程ID tid

3、printf ‘%x’ tid

线程ID转为16进制

4、jstack pid | grep -C 5 tid

查看进程中占用CPU最高的线程,发现是GC线程

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007f181001d800 nid=0x31a7 runnable


"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007f181001f800 nid=0x31a8 runnable


"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007f1810021800 nid=0x31a9 runnable


"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007f1810023000 nid=0x31aa runnable

5、jstat -gc pid 500

查下GC情况,发现几乎每秒发生一次FULL GC

6、jmap -dump:format=b,file=/tmp/**.dump pid

dump出jvm堆内存数据

7、通过mat(Eclipse Memory Analysis Tools)分析dump文件

导入dump文件分析后,发现有两大块数据异常,占用了整个堆内存的80%左右

M7viIjZ.jpg!web

第一块是下面109.8MB的这个,继续分析是 com.mysql.jdbc.JDBC4ResultSet 这个对象占用的,通过代码最终定位到问题,是一个定时任务批量处理数据时没有分页处理,一次查出了80W+的数据,然后遍历处理,导致GC时内存不能得到释放,这里改为分页处理后,问题解决。

YBJzUvb.jpg!web

第二块是 com.alibaba.druid.stat.JdbcDataSourceStat 这个对象占用了210.3MB。

yMniaaI.jpg!web

从名字可以看出这个类是druid用做统计的,他会记录最近n(默认1000)条的SQL执行情况, sqlStatMap 这个Map是记录了最近1000条的SQL的执行情况,看看代码。

sqlStatMap = new LinkedHashMap<String, JdbcSqlStat>(16, 0.75f, false) {

protected boolean removeEldestEntry(Map.Entry<String, JdbcSqlStat> eldest) {

boolean remove = (size() > maxSqlSize);

if (remove) {

JdbcSqlStat sqlStat = eldest.getValue();

if (sqlStat.getRunningCount() > 0 || sqlStat.getExecuteCount() > 0) {

skipSqlCount.incrementAndGet();

}

}

return remove;

}

};

但是从图里可以看出这里其实只记录了203条SQL的执行情况,却占用了200多MB,理应没有这么大的,sqlStatMap的key其实就是我们执行的SQL,继续看sqlStatMap里面的值,发现了几个特别大的key,SQL内容是这样的 update t_table set a=b where id in (id1,id2,id3....) ,这条SQL的查询条件in里面包含了几十万个id,占用空间10多MB,所以导致了sqlStatMap占用空间大。

所以这里的解决办法是:

1、先关闭druid的统计功能(我们并没有用到这个功能),释放 JdbcDataSourceStat 的内存占用;

<!-- 配置 p:filters="stat" 即开启druid的统计功能 -->

<bean id="dataSource" class="com.alibaba.druid.pool.DruidDataSource"

p:filters="stat"

p:connectionProperties="config.decrypt=true"/>

2、优化业务处理,采用分页的方式处理 。

总结

  • 大量数据一定要用分页的方式处理

  • 如非必要可以关闭druid的数据统计功能,可以节省大量的内存空间


About Joyk


Aggregate valuable and interesting links.
Joyk means Joy of geeK