背景
最近将接口发布到现网后,不定期会发生接口响应超时问题,进行重启后恢复。
猜测原因
该接口的功能主要为查询HBase数据再返回给前端,初步怀疑为HBase集群问题,在查询HBase前后打印日志,发现接口超时的时候,查询耗时一直处于10s以上。但是该接口服务分布式部署了多台机器,其中只是某一台接口机超时,其实机器响应正常,且查看HBase集群负载和网络情况均无异常。于是怀疑为该接口服务发生了full gc。
验证猜想
打印GC日志
JVM启动增加如下参数:
-XX: PrintGCDetails // 用于输出GC详细日志。
-XX: PrintGCDateStamps //用于输出GC时间戳(日期形式)
-XX: PrintTenuringDistribution //查看每次minor GC后新的存活周期的阈值
-XX: PrintHeapAtGC //在进行GC前后打印出堆的信息。
-XX: PrintReferenceGC //打印年轻代各个引用的数量以及时长
-XX: PrintGCApplicationStoppedTime //打印垃圾回收期间程序暂停的时间,可与上面混合使用
-Xloggc:/data/log/xserver/gc-%t.log //把相关日志信息记录到文件以便分析,与上面几个配合使用
-XX: UseGCLogFileRotation // 打开GC日志滚动记录功能
-XX:NumberOfGCLogFiles=14 //设置滚动日志文件的个数,必须大于等于1
-XX:GCLogFileSize=100M //设置滚动日志文件的大小,必须大于8k,当前写日志文件大小超过该参数值时,日志将写入下一个文件
-XX: HeapDumpOnOutOfMemoryError //当JVM发生OOM时,自动生成DUMP文件。
-XX:HeapDumpPath=/data/log/xserver //表示生成DUMP文件的路径,也可以指定文件名称
当服务再次超时的时候
发现服务生成了dump 文件,于是分析dump文件
下载及安装mat
下载地址:
https://www.eclipse.org/mat/downloads.php
拷贝到目录下,进行解压:
unzip MemoryAnalyzer-1.10.0.20200225-linux.gtk.x86_64.zip
修改MAT的内存大小, 注意这个大小要根据你dump文件大小来的,如果dump文件是10GB那么 这里最好配置大于10GB,否则会报MAT内存不足的异常,由于我的dump 有29G,于是设置了30G
vim MemoryAnalyzer.ini -Xmx30760m
分析dump 文件
./ParseHeapDump.sh dump文件名称
org.eclipse.mat.api:suspects org.eclipse.mat.api:overview org.eclipse.mat.api:top_components
等待结果,产生了如下三个zip文件,直接拷贝到本地解压用浏览器查看index.html
jmap_Leak_Suspects.zip jmap_System_Overview.zip jmap_Top_Components.zip
查看分析文件发现有几个超大的HBase Result 对象
查询代码,分析原因
查询HBase 使用的是scan模式,当查询的访问特别大时,直接将所有结果放入到了List中,导致jvm 发生了Full GC,于是该时间段内所有请求都超时。
解决办法
修改查询HBase的查询方式,迭代返回查询的数据,之后,接口再也没有超时啦~