专栏名称: SegmentFault思否
SegmentFault (www.sf.gg)开发者社区,是中国年轻开发者喜爱的极客社区,我们为开发者提供最纯粹的技术交流和分享平台。
目录
相关文章推荐
程序员之家  ·  急了!ChatGPT开放色情内容生成。。。 ·  4 天前  
待字闺中  ·  DeepSeek“七问”李国杰院士 ·  2 天前  
程序猿  ·  患者带着DeepSeek来看病,医学博主自嘲 ... ·  4 天前  
程序猿  ·  突发!百度出手,152亿元大收购 ·  2 天前  
51好读  ›  专栏  ›  SegmentFault思否

记一次线上 CPU 超高的排查过程

SegmentFault思否  · 公众号  · 程序员  · 2017-11-07 08:00

正文

最近发现公司一个主机的CPU每隔几天就飚上去,导致机器上部署的服务不可用。

top

显示进程18781占用CPU超过190%(主机是双核)。 top -Hp 18781 其中线程18783和18784各自的CPU都达到了99%。 jstack 18781 >> jstack.out 把JVM的线程信息导出到文件。

printf '%x\n' 18783 printf '%x\n' 18784

线程ID转换成16进制

在导出的线程栈文件jstack.out里查找495f和4960,对应的是gc线程,初步推断是内存泄漏导致的频繁gc。

jstat -gcutil 18781 1s

可以看到每隔几秒就会full gc,而且Eden和Old都是99%,就是说每次full gc都没有回收到多少内存,所以一直在反复的跑。

现在要把虚拟机内存导出,分析内存中是哪些对象占用大量空间不释放,因为HeapDump在生产环境是没有打开的(幸好没有打开HeapDumpBeforeFullGC ,不然就不止是CPU高了,按这几秒full gc一次的频率,用不了多久把磁盘也要撑爆),所以要用到一个小工具jinfo。

jinfo是jdk中自带的一个工具,用来查看运行中的虚拟机的参数,甚至在运行时动态修改一些JVM参数。

java -XX:+PrintFlagsFinal -version | grep manageable

用jinfo打开以下选项,把full gc前后的虚拟机内存dump下来。

jinfo -flag +PrintGC 18781 jinfo -flag +PrintGCDetails 18781 jinfo -flag HeapDumpPath=/home/work/data/heapdump 18781 jinfo -flag +HeapDumpBeforeFullGC 18781 jinfo -flag +HeapDumpAfterFullGC 18781

PrintGC和PrintGCDetails把gc日志输出到了nohup.out,查看nohup文件,可以看到full gc前后各dump了一次虚拟机内存,然后赶紧用jinfo关掉gc选项,选项前+号表示打开,-号表示关闭。


jinfo -flag -HeapDumpBeforeFullGC 18781

jinfo -flag -HeapDumpAfterFullGC 18781

在HeapDumpPath下找到dump下来的hprof文件,用mat打开,Linux下没有找到相关的工具,所以我先把文件下载到本机,用window版的mat打开。

SessionFactoryImpl占了1个多G,超过99%。打开Reports>Leak Suspects

Retained Size=当前对象大小+当前对象可直接或间接引用到的对象的大小总和,所以问题出在第一项的引用链上。点这一项的List Objects>with incoming references.

这个queryPlanCache是hibernate对SQL语句的缓存,可以参考stackoverflow上一位前辈的经验, https://stackoverflow.com/questions/31557076/spring-hibernate-query-plan-cache-memory-usage ,看来是太多数据库in查询造成了大量的SQL缓存,此时回头再看线程栈stack.out的信息,确实有很多Running状态的at com.sun.proxy.$Proxy131.findByIdIn(Unknown Source),这样就说的通了。

下一步,优化代码吧。


相关文章推荐







请到「今天看啥」查看全文