JVM完全解读之GC日志记录分析
相信大家在系统学习jvm的时候都会有遇到过这样的问题,散落的jvm知识点知道很多,但是真正在线上环境遇到一些莫名其妙的gc异常时候却无从下手去分析。
关于这块的苦我也表示能够理解,之前光是JVM相关的八股文就整理了许多,但是经常是不知道如何在实战中使用。最近也尝试在模拟一些案例来训练自己的JVM相关知识,本文特意记录下这段调优经历。
Java应用的GC评估
可能大多数程序员在开发完某个需求之后,往线上环境一丢,然后就基本不怎么关注后续的变化了。但是是否有考虑过,这些新引入的代码会对原有系统造成的影响呢?下边我们通过一段实战来带各位读者较好地去深入理解这个过程。
模拟场景
有一个应用程序(暂且称呼为moment服务)准备在小程序上开展社交动态推送功能,大概就是每次用户刷新页面时候便会按照一定规则推送出20条用户动态数据。由于该产品的c端用户数量比较多,于是便在上线该产品之前进行了相应的压测,判断该功能的承载能力。
在压测开始的初期,接口响应速度都还可以,但是渐渐地开始加压的时候,发现程序出现了OOM。经过排查后,排除数据库层的问题。于是开始怀疑是否是Java应用内部出现了异常。
应用的启动参数:
java -Xmx1512m -Xms1512m -Xmn1024m -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:log/gc.log -jar qiyu-framework-demo-jvm.jar
单节点压测,压力测试10w次请求,1000并发。使用ab工具进行压力测试:
ab -n100000 -c1000 http://localhost:8080/user/batch-query
jstat 查看GC,每隔5秒打印一次,持续20次
jstat -gc 5673 5000 20
经过一段时间的施压,在施压的持续了1分钟之后,YGC的频率让人感觉着实有些高。通常一个健康的系统ygc应该是20-30min左右一次,full gc可能是好几周才一次。
通过jstat可以看出,年轻代的gc会比较频繁,并且停顿时间严重影响了正常的业务使用。为了得到更加精准的数据,我尝试将gc日志放到GCeasy工具上进行可视化分析:
这是一款非常不错的gc日志分析工具
https://www.gceasy.io/
GC日志的可视化分析
首先是JVM内存中的占用分析,很清晰地可以看出,年轻代的内存和老年代的内存几乎占满,元空间基本没有变动过。
然后是整个系统的GC耗时分析:
从整体来看,大部分的GC耗时都是在0-100ms内,极端情况下的GC耗时可能会达到700ms。
接下来是看看GC回收对堆内存整体的一个影响。观测发现,基本每次GC都能够回收达改200mb左右的内存。
再继续分析,可以发现CMS回收器在回收的各个阶段中所消耗的时间:初始标记,并发标记,修正标记,并发清除
除了单纯分析GC回收的耗时之外,这款工具还有个非常赞的功能,可以帮助我们分析这段时间内,该Java程序产生对象的速率:
可以发现,一秒大概要产生445mb的对象,大概一秒就会有2.5mb对象晋升到老年代。
内存逃逸分析没有发现异常记录。
通过对这份报告分析完毕之后,我的第一直觉告诉我,年轻代不足,需要对年轻代内存进行增加。但是仔细观察下,产生对象的速率竟然高达445mb/s,这感觉非常不正常啊,极度怀疑是程序内部存在大对象的情况。
于是尝试使用jvisualVM这款工具进行深入分析,通过对CPU样例的监控,发现了一些异常信息:
似乎这个方法对CPU的消耗比较高,接着是内存的一个监控:
此时大概可以定位出异常方法所在的位置了,接下来便是对系统内部的业务代码进行分析了。
最后排查结果发现,其实是系统内部的一个方法调用,加载了5k个User对象到内存中做计算,而每个User对象里存放了一个大小为1kb的byte数组。大概的代码逻辑为:
于是便需要从业务层面对该方法进行优化,例如调小5k这个数值,同时对User对象内的byte数组进行过滤(因为实际使用不到这个字段)。
调整后发现GC的频率降低了许多,比较正常。
频繁GC的排查思路总结
通过本次实验,大概能够梳理出Java应用在出现频繁GC的时候该如何去排查问题点,大致为:
通过结合工具分析GC日志,排查是否有大量对象频繁创建所导致。
通过对GC日志的分析能够排查出年轻代和老年代的GC频率。
通过对CPU占用比较高的线程,或者内存占用比较高的对象进行分析,定位异常点。
最后结合业务系统代码进行分析,精确定位异常点。
以上就是JVM完全解读之GC日志记录分析的详细内容,更多关于JVM解读GC日志记录分析的资料请关注猪先飞其它相关文章!
原文出处:https://mp.weixin.qq.com/s?__biz=MzU2MDU3MzE1Mg==&mid=224748
相关文章
浅谈Java自定义类加载器及JVM自带的类加载器之间的交互关系
这篇文章主要介绍了浅谈Java自定义类加载器及JVM自带的类加载器之间的交互关系,具有很好的参考价值,希望对大家有所帮助。一起跟随小编过来看看吧...2021-02-22- 这篇文章主要介绍了c# 如何用好垃圾回收机制GC,帮助大家更好的理解和学习c#,感兴趣的朋友可以了解下...2020-11-03
- 这篇文章主要介绍了教你一文搞懂Kotlin中的Jvm注解,文中通过示例代码介绍的非常详细,对大家的学习或者工作具有一定的参考学习价值,需要的朋友们下面随着小编来一起学习学习吧...2020-10-11
- 这篇文章主要介绍了java应用开发之JVM运行时内存,文中附含图文示例内容分析非常简要,有需要的朋友可以借鉴参考下,希望能够有所帮助...2021-09-16
- 这篇文章主要介绍了深入理解Java之jvm启动流程,文章内容讲解的很清晰,有对这方面感兴趣的同学可以研究下...2021-02-09
- 这篇文章主要介绍了JVM的种垃圾回收,文中通过示例代码介绍的非常详细,对大家的学习或者工作具有一定的参考学习价值,需要的朋友们下面随着小编来一起学习学习吧...2021-08-15
- 本篇文章是对Main函数中的参数argc,argv的使用进行了详细的分析介绍,需要的朋友参考下...2020-04-25
- Web server(ex: Apache2、Nginx..) 的存取留下 Log 可以观察很多东西、追踪、找问题 等等, 但是量太大的时候, 另外一个困扰也会出现, IO 吃紧, Loading 随著?高. 查官方...2016-01-28
- 这篇文章主要介绍了python垃圾回收机制(GC)原理解析,文中通过示例代码介绍的非常详细,对大家的学习或者工作具有一定的参考学习价值,需要的朋友可以参考下...2020-05-08
- 分享一篇关于php fopen实现mysql错误日志记录用法,因为数据库出错了我们肯定不能把错误日志保存到数据库了,所以我们利用了fopen来记录哦,有需要的朋友参考一下。 ...2016-11-25
- 在网上找了很多IIS日志分析工具,功能实在太有限,有的仅能分析百度、谷歌等搜索引擎爬虫的来访次数,远远达不到我们的用户的需求...2020-12-08
- 这篇文章主要为大家分享了最有价值的三道关于JVM的面试题,涵盖内容全面,包括数据结构和算法相关的题目、经典面试编程题等,感兴趣的小伙伴们可以参考一下...2021-09-12
- 这篇文章主要介绍了JVM系列之:再谈java中的safepoint说明,具有很好的参考价值,希望对大家有所帮助。一起跟随小编过来看看吧...2020-09-14
- 这篇文章主要介绍了JVM运行时数据区原理解析,文中通过示例代码介绍的非常详细,对大家的学习或者工作具有一定的参考学习价值,需要的朋友可以参考下...2021-08-16
- 这篇文章主要介绍了一文读懂Jvm类加载机制,文中通过示例代码介绍的非常详细,对大家的学习或者工作具有一定的参考学习价值,需要的朋友可以参考下...2021-08-16
- 这篇文章主要介绍了JVM内存模型的相关资料,帮助大家更好的理解和学习Java虚拟机,感兴趣的朋友可以了解详细...2020-10-15
- 本节将会介绍一下JVM的内存结构,JVM运行时数据区的各个组成部分:堆,方法区,程序计数器,Java虚拟机栈,本地方法栈,还会对Java堆的分代划分做个简单的介绍...2021-09-24
- 这篇文章主要介绍了Java系统运行缓慢等问题的排查思路,读者可以根据具体情况具体分析,从而解决问题...2021-04-22
- 我们天天都在使用java来new对象,但估计很少有人知道new出来的对象到底长的什么样子?对于普通的java程序员来说,可能从来没有考虑过java中对象的问题,不懂这些也可以写好代码。今天,给大家介绍一款工具JOL,可以满足大家对java对象的所有想象。...2021-06-02
- 这篇文章主要介绍了JVM中对象的创建与OOP-Klass模型,具有很好的参考价值,希望对大家有所帮助。如有错误或未考虑完全的地方,望不吝赐教...2021-09-11