最近刚上线了一款社交项目,运行十多天后(运营持续每天推量),发现问题:系统OOM(资源不能被释放)导致服务器频繁且长时间FGC导致服务器CPU持续飚高日志中内存溢出:java.lang.OutOfMemoryError: Java heap space程序十分卡顿,严重影响用户使用从以下方面,为大家分享此次问题解决流程问题出现现象临时解决方案复现问题定位问题发生原因优化代码优化后进行压测,上线复盘学完本博文,你的收获
排查内存溢出的思路排查内存溢出过程中用到的命令及工具(Linux命令,Eclipse Memory Anaylzer[MAT])定位系统内存溢出的代码,并进行优化此次内存溢出问题复盘
解决方案流程图
问题&临时解决方案&定位问题&最终解决方案
问题:
业务反馈程序用的十分卡,同时测试自己测的也十分卡从ELK收集的请求日志发现确实存在问题,线上是两台部署:两台机器上都是,一次请求耗时由原来的几毫秒变为10几秒CPU跑的过高,当时是4核,CPU持续飙到350%+;当时一台服务器CPU截图:
![](https://pics0.baidu.com/feed/9a504fc2d5628535165090e3f142cac1a5ef63f1.jpeg?token=4efb1b52b1e0ee8484bdaf225ec702f9&s=0DE47A2297FC298234C9050F000070C3)
临时解决方案:
当时为了减少对业务影响,直接将生产两台服务器上的项目进行重启项目启动参数中没有加内存溢出日志输出(后续博客为大家介绍JVM调优时讲解启动命令中加内存溢出日志输出),重启后出问题时项目的JVM信息丢失了
复现问题方式:在开发环境对程序进行持续压测;压测相关服务器配置:
服务器配置:8核,16G项目启动内存:136MJmeter持续(循环)下发消息接口10分钟
定位问题
top命令查看最耗CPU的进程(进程:17038;CPU持续飙到595%+)# 输入top命令后键入P(大写P),进程按照CPU从高到底排序top
![](https://pics1.baidu.com/feed/f2deb48f8c5494eef4a8487e4f585cf998257e07.jpeg?token=5680e52897ff6aba668bc9f2fdb4156b&s=2560DB02C3A4BEEA565488060200A0C3)
查看该进程中最耗CPU的线程(发现有一些线程占用CPU较高)# 17038为进程号,键入P(大写P),该进程中的线程按照CPU从高到底排序top -Hp 17038
![](https://pics4.baidu.com/feed/6c224f4a20a446237c41388bfa8fce090ef3d781.jpeg?token=1532aaa5dc5bae949c2cbd3bd9ea6469&s=05505B82D3A4BEE8586904910200F0C3)
将线程号转为16进制,同时查看这些线程当前正在干什么(在此以17045线程为例)# 将线程号转为16进制;其中17045为线程号
printf '%x\n' 17045# 17038为进程号, 0x4295为最耗CPU线程的十六进制
jstack 17038 | grep '0x4295' -C10 --color
![](https://pics3.baidu.com/feed/b03533fa828ba61e65cd3bc823992b0d314e596f.jpeg?token=eb9752f8879ab8f88c5e2aa1ef50e9d3&s=6D609B42D3F581CA08D4C509000070C1)
可以看到最耗CPU的线程都是在进行GC用Jmap命令查看当前堆的使用情况(发现老年代现在已占用99.8%+)# 其中17038为进程号jmap -heap 17038
![](https://pics1.baidu.com/feed/cc11728b4710b912a55dfe8ea150400493452252.jpeg?token=1be0288d098fbea135f82364c0c93187&s=2361DB027BB4A6CA5CC9D407000070C1)
查看gc频率的命令(其中O代表老年代占用率,FGC是FullGC次数,FGCT是fullGC时间;可以看出在频繁FullGC但是老年代有资源一直释放不掉)# 其中17038为进程号,5000是指每5秒(5000毫秒)
输出一次jstat -gcutil 17038 5000
![](https://pics2.baidu.com/feed/9f510fb30f2442a7e6dd43d0b3ee114cd013022c.jpeg?token=0e86e4a0b0536c6fd57cc23c94e08477&s=13705B82B7F9B1D25CFD9D0F02007082)
通过分析出问题时线上日志发现内存溢出;至此定位到问题根源是内存溢出导致(有未释放资源堆积,导致老年代被占满,然后频繁的FullGC但是资源一直释放不了)grep -m 10 'OutOfMemoryError' *.log
![](https://pics4.baidu.com/feed/e850352ac65c103817cc0738d7bc2f14b27e89cb.jpeg?token=d72b47be754cf2218ae32f5caabda8c2)
分析问题产生原因
由于线上当时直接重启,未能保留当时的JVM内存文件;在开发环境进行循环压测,复现线上问题,然后导出dump文件进行分析找到原因生成dump文件命令# 其中fileName是导出后dump名称,
pid为进程号jmap -dump:format=b,file=fileName.dump pid将dump文件导出到本地,
用Eclipse Memary Analysis(MAT官网下载地址) 进行分析MAT导入dump文件
![](https://pics6.baidu.com/feed/d833c895d143ad4b95f1f81ee3afe6a8a60f0641.jpeg?token=f52c0253ff8868aae17352db2c48f796&s=71323D9A85705C2108C199D6020010B1)
![](https://pics6.baidu.com/feed/cf1b9d16fdfaaf51b14584b9eef928e9f11f7a42.jpeg?token=1015933d45f28122a9c821efc4e63e33&s=20186C32150E654D58EDA5DA000050B3)
按对象排序视图进行查看(总览中看到对象总个数:14.1百万个)发现有两个类(ClassClassPath,ClassClassPathList)占用比较大,这两个类约占对象总数的83%(计算方式:5873361*2/14100000=83%)
![](https://pics4.baidu.com/feed/8435e5dde71190efb49c0f79aab62111fcfa6062.jpeg?token=4eccf24e0e98a33eb8088f35a3a8ad2d&s=510AFC1A11DC45C81269F9CA0000C0B1)
分析代码
去代码中全局搜这两个类,发现只有在打日志的时候用到ClassClassPath类
![](https://pics7.baidu.com/feed/29381f30e924b899e07df87d0daba1920b7bf663.jpeg?token=6ebbff16262cd163024b23706ee272b7&s=F910EC131D1E44CC4EF9A4D9020090B3)
分析ClassClassPath相关代码:
用到ClassClassPath对象是一个静态的ClassPool;问题原因:classPath一直被静态的全局pool所持有,导致GC一直释放不掉;
![](https://pics3.baidu.com/feed/c75c10385343fbf2510cf145d2d3768764388fed.jpeg?token=3654691eaf3c80f68d693e7ca53145ec&s=2912ED138D984CC81E59E8D10000D0B3)
![](https://pics2.baidu.com/feed/34fae6cd7b899e5177c55fd3230a6534ca950de6.jpeg?token=4a9ec35188f4fd8360ff9892c71586f0&s=5592E53315486D4D4C7D95DE0200D0B1)
![](https://pics3.baidu.com/feed/0823dd54564e92589226f0dafe2f6d5fccbf4e2c.jpeg?token=a253d05cd9ae393255980e523c5ea5b4&s=7D42EC1A198FD0CC1A789CDE020080B0)
![](https://pics0.baidu.com/feed/4610b912c8fcc3ce6003f54ff0e86a8fd53f203b.jpeg?token=351a1fbba2932c68588a4e0f97e9dfb1&s=6D82EC1A11EEF0EA407955DE000090B1)
当然顺着代码,顺藤摸瓜也找到了ClassPathList
![](https://pics3.baidu.com/feed/3bf33a87e950352ac1d22a7f31ee47f5b3118b4e.jpeg?token=c5f341fc72f8fe8f8d326041f238eebc&s=2116EC3219D8C8CA58D471DC020090B2)
![](https://pics2.baidu.com/feed/3bf33a87e950352a1f7d780731ee47f5b3118bd2.jpeg?token=35b396941d906ac8a9ae90bc8a5e8519&s=D592EC32119869C81E5C00D3020050B2)
优化代码:每次用完ClassClassPath后将其释放
每次对象使用完后从静态pool中移除注意:classPath=null这种方式是不能释放掉的
![](https://pics0.baidu.com/feed/8b82b9014a90f603748a49625bbf0f1cb051ed16.jpeg?token=e9526b9d81fb407ce9a63dd6a3d405d8&s=6980EC1211EEECE81A6D00DE000090B1)
优化后再次进行验证
开发环境循环压测,用MAT分析dump文件,发现内存中已不再堆积ClassClassPath类;优化前后接口吞吐量也提升8.2%进行线上发布,观察一周后,对内存分析发现正常
复盘:
为快速开发,社交的代码从原来金融项目基础上改造而来;原来金融项目没有内存溢出,而社交项目为什么内存溢出?通过ELK统计一段时间的访问量结果:社交和金融项目业务类型不一样,所呈现出的特点也不同去生产的金融项目中dump内存文件,用MAT工具分析,发现也存在ClassClassPath类堆积释放不掉,只不过由于访问量少,堆积量未占满老年代而已;果断在金融项目迭代时将其优化;社交目前日访问后台量65w+金融项目只有4.5W+项目比对:
程序预警:为减少业务影响,增加接口耗时的预警(后续博文为大家共享);实现方式:
- 在每次程序处理完进行预警(比如本次请求>阈值);缺点:消耗性能影响正常业务- 在ELK清洗时用相关插件进行预警;优点:和业务解耦,对业务无影响
服务器预警:运维增加CPU内存,日志内存溢出监控
总结
解决内存溢出过程总结:不同的项目导致内存溢出原因是不同的;重要的是排查思路经过不断的耐心的去观察,测试,分析才能定位到问题并最终解决问题在这次分析内存溢出过程中,我们也针对我们项目的JVM启动参数进行了调优,在接下来的博文中为大家分享JVM调优
摘自:
https://baijiahao.baidu.com/s?id=1686018981169577176&wfr=spider&for=pc