java 内存泄露 书籍_[Java教程]一次艰难的内存泄露排查，BeanUtils 的锅
[Java教程]一次艰难的内存泄露排查，BeanUtils 的锅
0 2020-10-29 18:24:42
现象
通过jstat -gcutil pid 5000 ,发现fgc次数很多而且频繁，此时老年代占比已经大约70%左右，且已经回收不了内存，我们这边设置的fgc阈值是老年代的70%。此时因为还有30%的老年空间，所以整体内存相对还算稳定，CPU也比较稳定，但是有很大的潜在的风险，就是内存一直上涨，不释放。 [service@ZQ-SE-331-V05 ~]$ jstat -gcutil 1087 5000 S0 S1 E O M CCS YGC YGCT FGC FGCT GCT 0.00 55.09 88.41 72.10 92.64 85.22 9223 1169.442 435 168.866 1338.307 57.54 0.00 82.24 72.31 92.64 85.22 9224 1169.542 436 168.877 1338.418 0.00 63.75 5.33 72.50 92.64 85.22 9225 1169.642 436 168.877 1338.519 0.00 63.75 34.02 72.50 92.64 85.22 9225 1169.642 436 168.877 1338.519 0.00 63.75 59.26 72.50 92.64 85.22 9225 1169.642 436 168.877 1338.519 0.00 63.75 81.37 72.50 92.64 85.22 9225 1169.642 436 168.877 1338.519 55.60 0.00 11.75 72.71 92.64 85.22 9226 1169.742 436 168.877 1338.619 55.60 0.00 40.07 72.71 92.64 85.22 9226 1169.742 436 168.877 1338.619 55.60 0.00 67.86 72.70 92.64 85.22 9226 1169.742 437 169.541 1339.284 0.00 56.04 4.21 72.59 92.64 85.22 9227 1169.838 437 169.541 1339.379 0.00 56.04 30.01 71.73 92.64 85.22 9227 1169.838 438 169.649 1339.487 0.00 56.04 57.75 71.73 92.64 85.22 9227 1169.838 438 169.649 1339.487 0.00 56.04 79.01 71.73 92.64 85.22 9227 1169.838 438 169.649 1339.487 55.39 0.00 2.54 71.92 92.64 85.22 9228 1169.988 438 169.649 1339.638 55.39 0.00 24.70 71.92 92.64 85.22 9228 1169.988 438 169.649 1339.638 55.39 0.00 47.89 71.92 92.64 85.22 9228 1169.988 438 169.649 1339.638 55.39 0.00 82.01 71.89 92.64 85.22 9228 1169.988 439 170.207 1340.196复制代码
初步猜测是出现了内存泄露，通过jmap -histo/-histo:live pid >> log导出fgc前后的histo对比，发现了一个实例数很大的对象CarnivalOneDayInfo，达到了2kw级别，而且一直在增加 num #instances #bytes class name---------------------------------------------- 1: 28906840 1387528320 java.util.HashMap 2: 38675870 1237627840 java.util.HashMap$Node 3: 18631826 745273040 xxx.CarnivalOneDayInfo num #instances #bytes class name---------------------------------------------- 1: 31092889 1492458672 java.util.HashMap 2: 35749328 1143978496 java.util.HashMap$Node 3: 20355334 814213360 xxx.CarnivalOneDayInfo复制代码
排查
直接看CarnivalOneDayInfo(嘉年华)相关代码，因为之前的测试大概知道这个问题，所以很快的定位到是在每分钟的MinuteJob中检查所有在线玩家的时间活动的时候，相关逻辑会克隆一个CarnivalOneDayInfo。所以初步定位是CarnivalOneDayInfo不断clone的问题
后端y同学看了一下相关逻辑，本地把相关clone逻辑注释后，再次本地观察histo，发现该对象实例不在增加，再次确认1的推论，但看了一下活动相关代码，所有活动的检查都是clone了一份，为什么只有嘉年华活动泄露？看相关代码，发现clone出来的对象都是临时对象，应该会被fgc的，如何泄露呢？
所以直接开始操作第一步，准备查CarnivalOneDayInfo是被谁持有引用，查这个问题的话，必须要把内存堆快照dump出来，然后利用工具检查，如mat。但是线上玩家很多，而且堆内存很多，导出一次很花费时间，会stw，所以直接连开发服务器，查了一下，一样存在CarnivalOneDayInfo泄露的问题，所以直接利用jmap -dump:live,format=b,file=2388_heap.bin 2388，导出开发服务器java进程的堆内存快照。
直接利用mat打开，对mat使用有经验的话，操作步骤是选择dominator_tree
搜索CarnivalOneDayInfo
List Objects
选择With incoming references，谁持有了它的引用
直接发现是被 queue-executor-handler-5 java.lang.ThreadLocal$ThreadLocalMap @ 0x8104eec0 java.lang.ThreadLocal$ThreadLocalMap$Entry[64] @ 0x866710f0 java.lang.ThreadLocal$ThreadLocalMap$Entry @ 0x86671608 java.util.IdentityHashMap @ 0x86671628复制代码
java.lang.Object[]，通过查看这个属性，可以看到其大量持有了CarnivalOneDayInfo和HashSet从上面可以很确定的是，CarnivalOneDayInfo是直接被逻辑线程的threadlocal持有。
艰难的分析之路
逻辑线程的threadlocal怎么会持有CarnivalOneDayInfo，从代码和想法上感觉不可思议，我这边的第一步是直接在ide中查所有ThreadLocal的引用，发现logback
protobuf
业务自己的threadlocal
BeanUtils的threadlocal
排查后，简单测试了一下，和查了一下相关代码，发现没有什么思路和投诉。觉得beanutils和logback有点问题，但是感觉和CarnivalOneDayInfo关系也不大，于是下面我的重点在于想从mat入手，看看能不能从中找出threadlocal的名字，但最终是被证明是徒劳的，只有引用地址，不过我们z同学从是debug的排查思路出发的在ThreadLocal的set和setInitialValue打断点，然后跑游戏，重点断点在MinuteJob，向逻辑线程投递消息检查活动状态这块每次调用checkTimeActivity，都去观察每个ThreadLocal$ThreadLocalMap$Entry
然后重点观察是否出现IdentityHashMap，因为上面mat分析到了是这个map终于定位到堆栈。
堆栈MinuJob -> 遍历在线所有玩家，向逻辑线程投递消息 -> ActivityManager#checkTimeActivity
遍历所有个人活动 -> CarnivalActivityInfo#checkActivityState
CarnivalActivityInfo diff = playerInfo.clone() // 在这里clone了一份
checkIsSameState -> activityBaseInfo.getCarnivalDaysMap().equals(carnivalDaysMap) // 调用equals比较
去依次比较CarnivalDaysMap中每一个CarnivalOneDayInfo
调用CarnivalOneDayInfo -> BaseCarnivalOneDayInfo # equals
BeanUtils.isDirty
具体代码 private static Set getDirtyNamesByBean(AugmentedBean augmentedBean) { IdentityHashMap> dirtyNamesMap = dirtyNames.get(); if (dirtyNamesMap == null) { dirtyNamesMap = new IdentityHashMap<>(); dirtyNames.set(dirtyNamesMap); } return dirtyNamesMap.computeIfAbsent(augmentedBean, k -> Sets.newHashSet()); } public static boolean isDirty(AugmentedBean augmentedBean) { return getDirtyNamesByBean(augmentedBean).size() > 0; }复制代码
从上面可以非常容易的看到是这里创建了一个IdentityHashMap，然后set到了threadlocal中和之前的分析如出一辙至此完全定位问题是，是BeanUtils的锅。
复盘和总结
其实非常怀疑过beanutils的问题，但是没有太仔细注意，现在一看，和上面的分析一模一样，分析内存泄露，思路：对比fgc前后的histo，确认那些对象实例数一直在增加，而且明显偏大
分析代码，如果直接定位问题，最好
如果不能直接定位，需要确认是谁持有该对象引用，那么需要dump堆内存快照
但是不能在线上dump，需要在开发服务器复现(内存泄露通常比较容易复现)，然后在开发服务器dump
dump出来后，利用mat工具分析泄露，List Objects With incoming references，找到引用
下一步是需要确认为什么这里会引用，可以分析代码，解决问题，最好
如果不能，那么可以使用debug的方式，在上一步引用相关对象的代码出加断点，确认线程堆栈
也解释了为什么只有嘉年华活动有泄露，因为只有它调用了beanutils生成的basexx的equals方法，其他都没有调用，beanutils是当初clone对象的一个解决方案，用来回滚和diff，增量更新，后来该方案废弃，因为会随着对象的复杂度提高而导致clone成本高，但是遗留了一大部分生成的代码，而这次的bug也是因为调用了废弃的生成代码的方法。所以下一个版本一定将所有生成的废弃代码清理一遍
后续解决办法。
发现了beanutils的这个问题后，那么很容易解决泄露问题了。我写了一个beanshell脚本，向逻辑线程投递了消息，调用 BeanUtils.clean，清理所有threadlocals import x.BeanUtils;import y.HandlerModule; for (int i = 1; i <= 16; i++) { HandlerModule.instance.addQueueTask(i, new Runnable() { public void run() { BeanUtils.clean(); } });}复制代码
在用jstat看了一下，CarnivalOneDayInfo经过fgc后，从kw到了百万，老年代占用也从70到了30 $ jstat -gcutil 1087 5000 74.73 0.00 16.02 72.48 92.61 85.04 10156 1313.117 575 271.355 1584.472 74.73 0.00 34.71 72.48 92.61 85.04 10156 1313.117 575 271.355 1584.472 74.73 0.00 54.42 72.48 92.61 85.04 10156 1313.117 575 271.355 1584.472 74.73 0.00 73.29 72.48 92.61 85.04 10156 1313.117 575 271.355 1584.472 74.73 0.00 89.41 72.48 92.61 85.04 10156 1313.117 575 271.355 1584.472 0.00 71.54 9.25 72.74 92.64 85.06 10157 1313.303 576 272.188 1585.492 0.00 71.54 28.30 72.73 92.64 85.06 10157 1313.303 577 272.188 1585.492 0.00 71.54 55.85 72.73 92.64 85.06 10157 1313.303 577 272.463 1585.766 0.00 71.54 78.05 72.73 92.64 85.06 10157 1313.303 577 272.463 1585.766 69.21 0.00 1.70 70.98 92.64 85.06 10158 1313.438 578 273.320 1586.758 69.21 0.00 19.97 63.09 92.64 85.06 10158 1313.438 578 273.320 1586.758 69.21 0.00 39.82 53.33 92.64 85.06 10158 1313.438 578 273.320 1586.758 69.21 0.00 59.75 41.61 92.64 85.06 10158 1313.438 578 273.320 1586.758 69.21 0.00 75.12 31.79 92.64 85.06 10158 1313.438 578 273.320 1586.758 69.21 0.00 94.13 31.79 92.64 85.06 10158 1313.438 578 273.320 1586.758 0.00 86.02 15.60 32.07 92.64 85.06 10159 1313.761 578 273.320 1587.081 0.00 86.02 94.86 32.07 92.64 85.06 10159 1313.761 578 273.320 1587.081 [service@ZQ-SE-331-V05 config]$ jmap -histo 1087 | grep CarnivalOneDayInfo 10: 1408627 56345080 xxx.CarnivalOneDayInfo复制代码
另外后面的优化方案是重构活动代码，另外即使用equals，也不用之前beanutils生成的类的equals比较，避免beanutils threadlocals的泄露问题。
关于内存问题，在正式上线之前，一定要可根据同时在线人数，dau等准确预估整体占用内存，如一个player的实际的占用内存，全局静态数据如排行榜的实际占用内存等。可以通过代码和工具获取。这样能快速确认是否是出现了内存泄露还是真的比较占内存。
看完三件事❤️
如果你觉得这篇内容对你还蛮有帮助，我想邀请你帮我三个小忙：点赞，转发，有你们的 『点赞和评论』，才是我创造的动力。
关注公众号 『 java烂猪皮 』，不定期分享原创知识。
同时可以期待后续文章ing
java 内存泄露 书籍_[Java教程]一次艰难的内存泄露排查，BeanUtils 的锅相关推荐
- eclipse java启动参数设置_[Java教程]eclipse.ini配置eclipse的启动参数
[Java教程]eclipse.ini配置eclipse的启动参数 0 2013-09-28 01:00:11 Eclipse的启动由$ECLIPSE_HOME/eclipse.ini控制,如果$EC ...
- java visualvm远程监控_如何监控和诊断堆外内存使用
如何监控和诊断堆外内存使用 可以使用综合性的图形化工具,如 JConsole.VisualVM ,这些工具比较直观,直接连接到 Java 进程,图形化界面. 可以使用命令工具进行查询,如 jstat ...
- java privatekey输出字符串_[Java教程]根据字符串（String）生成公钥（PublicKey）和私钥（PrivateKey）对象_星空网...
根据字符串(String)生成公钥(PublicKey)和私钥(PrivateKey)对象 2012-05-29 0 1.字符串生成公钥对象 PublicKey /** * 实例化公钥 * * @re ...
- java 基础面试 英文_[Java面试] 面试java基础总结大全
原标题:[Java面试] 面试java基础总结大全 基础知识: 1.JVM.JRE和JDK的区别: JVM(Java Virtual Machine):java虚拟机,用于保证java的跨平台的特性. ...
- java 字符串格式替换_[Java] - 格式字符串替换方法
Java 字符串格式替换方法有两种,一种是使用String.format(...),另一种是使用MessageFormat.format(...) 如下: import java.text.Messa ...
- java 查看dump文件_[JAVA]JAVA章3 如何获取及查看DUMP文件
一.dump基本概念 在故障定位(尤其是out of memory)和性能分析的时候,经常会用到一些文件来帮助我们排除代码问题.这些文件记录了JVM运行期间的内存占用.线程执行等情况,这就是我们常说的 ...
- java视、频_[java视频]感人故 事视 频网 站上那找~~~
感人故 事视 频网 站上那找~~~ 问题补充:感人故 事视 频网 站上那找~~~ ●呵呵,你问对人了,感人故事就去"新浪show",现在是新浪期下的网站,运行稳定,观看流畅,上传简 ...
- java 历遍 类_[Java] 遍历指定包名下所有的类(支持jar) | 学步园
项目需要,仅做记录. 支持包名下的子包名遍历,并使用Annotation(内注)来过滤一些不必要的内部类,提高命中精度. 通过Thread.currentThread().getContextClas ...
- java 图片宽高_[Java]获取图片高和宽
通过javax.imageio.ImageIO类中的read()函数读取的图片,存放在类java.awt.image.BufferedImage类中.调用BufferedImage类中的getWidt ...
最新文章
- 常用API（Object、String、StringBuffer、用户登陆注册)
- bmp调色板颜色信息重复_PASCAL VOC数据集-分割标签索引颜色对照及程序
- 天线的基本原理和概念
- 史上最全！近千篇机器学习自然语言处理论文！都这儿了
- leetcode 滴滴_一个菜逼程序媛的求职历程（秋招已拿阿里、网易、滴滴等校招offer）...
- 查看linux文件系统结构,如何查看Linux系统架构类型
- 5种ASP.NET页面间传递参数实例代码
- 动态链接（指向运行时常量池的方法引用）
- [转]MPlayer快捷键参数设置--系统开销最少的影音播放器
- 王爽 汇编语言第三版 第7章 --- 更灵活的定位内存地址的方法（可以理解为 数组形式的内存定位）
- hbuilder php mysql_xampp本地服务器+HBuilder配置php环境
- 《Spring实战》系列之Bean的装配-Days01
- CSS动画transform、transition和animation的区别
- qxdm无法安装问题闪一下_Qualcomm QXDM
- （21）tar打包命令详解
- proteus——rs-232双机通讯
- ffmpeg命令详细说明
- leetcode 笨阶乘
- LruCache算法原理解析
- 竞争情报分析工具Alexa