本文由 简悦 SimpRead 转码, 原文地址 www.toutiao.com
一、背景
某日早上,生产环境告警群出现了大量响应时间在 1s 多的慢接口,在应用日志中也能找到不少接口超时熔断(响应时间 >=5s)。
当中有不少接口的 SQL 是能使用索引的,经过 DBA 排查,数据库没有问题。
在主机上使用 top 命令查看 CPU 占用情况,发现有异常:部分主机 CPU 在 50% 上下,其中一台主机 CPU 偶尔就上到 300%,一直持续。
二、CPU 高排查
- 查消耗 Cpu 最高的进程 PID 41594
shell 命令:top -c
- 根据 Pid 查出消耗 Cpu 最高的线程号 41600
shell 命令:top -Hp 41594
- 这是十进制的数据,转成十六进制为 a280
shell 命令:printf “%x\n” 41600
- 导出 PID 的堆栈信息
shell 命令:jstack -l 41594 > 41594.stack
- 在 41594.stack 中搜索线程号关键字 “a280”,发现以下行
“GC task thread#4 (ParallelGC)” os_prio=0 tid=0x00007f41f8026800 nid=0xa280 runnable
搜了 top 5 的线程号,发现都是 GC 的线程,说明是堆内存出了问题。
三、监控情况
通过 Grafana 监控查看 JVM 内存以及 GC 情况,发现堆内存基本满了
GC 次数和时间明显增加
这种情况下就需要获取内存快照来分析,导出内存快照
shell 命令:jmap -dump:format=b,file=dump-20210809.hprof 41594
压缩文件后在进行下载
shell 命令压缩:tar -czf dump-20210809.hprof.tar.gz dump-20210809.hprof
shell 命令下载:sz dump-20210809.hprof.tar.gz
四、dump 分析
利用工具 MemoryAnalyzer(MAT)分析 dump 文件,发现 1.4G 的内存都是 com.alibaba.fastjson.parser.ParserConfig 这个类占用的
展开 list_objects 视图查看发现 1.4G 都耗在 com.alibaba.fastjson.util.IdentityHashMap
网上查询相关资料,发现也有相关问题:fastjson 反序列化使用不当导致内存泄露 - liqipeng - 博客园
在代码中搜索关键字‘ParameterizedTypeImpl’,果然是有使用的
至此,问题已经定位到,跟资料说的一模一样。
接下来就要重现这个问题,写一段循环不停的执行这段代码,循环 10 万次,然后把堆内存 dump 出来对比。
结果如下,有 346M 都是 com.alibaba.fastjson.parser.ParserConfig 这个类占用的
com.alibaba.fastjson.util.IdentityHashMap 表现也一致
网上资料也提供了相关的解决方案,这里使用了‘方法二’
再 dump 出堆内存快照, com.alibaba.fastjson.parser.ParserConfig 已经不出现在视图里了