一次内存溢出排查过程
导出超过20W条数据到excel。
默认使用poi提供方法XssfWorkBook进行写入Excel。
分页查询数据,每次查询完之后,写入到Excel。
现象
在写入数据10W+的时候,用时2分钟左右;
但10W+之后,速度开始慢了下,导出20W数据大约需要30分钟左右;多次导出之后,出现内存溢出问题。
排查
猜测1
怀疑sql查询太慢,超过10W条数据可能出现了深度翻页的问题。
但是通过增加日志,打印执行时间,发现用时并没有太久(同时,sql查询也有超时时间,超过5s左右会终止查询,抛出异常,而这种情况并没有出现)。
猜测2
怀疑可能是Excel文件太大了,后面写入会增加时间,导致速度慢下来了。但是通过增加打印日志,发现耗时基本是可以忽略的。
猜测3
在导出过程中,页面进行其他操作,接口出现超时。怀疑是jvm在做full gc,出现了“Stop The World”情况。
通过arthas 监控内存,以及通过jmap -histo 命令观察gc情况,发现事实是这样,执行full gc的次数很频繁,而且每次执行完full gc之后,堆内存的情况并没有很明显的减少,导致出现了频发full gc的情况。
通过jmap -heap 命令查看内存分布情况,发现排名靠前的对象有类似dom4j的东西,所以怀疑是写入Excel导致内存泄露。
解决方法:SXssfWorkBook替换XssfWorkBook。问题解决。
使用到的工具和命令
- arthas
- jmap -histo [pid] [interval]
- jmap -heap >> test.txt
其他现象
在线上环境,偶尔会收到报警调用ES超时;
一般情况下都是ES所在的机器jvm发生full gc;
导致full gc的原因:某个商家做活动,一段时间内涌入了大量的流量,导致ES内存增长很快,所以产生了full gc。在full gc的时间段内,对外基本不提供服务,接口超时。
arthas
dashboard
当前系统的实时数据面板
线程信息(部分)、内存、GC次数、GC时间、基本信息
thread
显示线程信息
thread -n 指定最忙的前N个线程并打印堆栈
jvm
jvm的配置信息
sc
打印类的详细信息
打印类中详细信息以及变量信息
sm
查看已加载类的方法信息
查看方法的详细信息
monitor
非实时返回
-c :统计周期,默认为120秒
监控项:
timestamp 时间戳
class java类
mehtod 方法(构造方法、普通方法)
total 调用次数
success 成功次数
fail 失败次数
rt 平均rt
fail-rate 失败率
monitor class-pattern method pattern
trace
方法内部调用路径,并输出方法路径上的每个节点的耗时
trace class-pattern method-pattern -n #cost
trace *StringUtils isBlacnk '$cost>100'
stack
查看某个方法的调用路径-堆栈信息
watch
grovy 表达式
watch com.example.demo.arthas.ArthasInnerService test2 "{params.length,params[0],returnObj.age}" returnObj.books.size()>4
网友评论