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日志记录分析的资料请关注我们其它相关文章！

赞 (0)

相关推荐

  • 深入了解Java GC的工作原理

    深入了解Java GC的工作原理

    JVM学习笔记之JVM内存管理和JVM垃圾回收的概念,JVM内存结构由堆.栈.本地方法栈.方法区等部分组成,另外JVM分别对新生代下载地址  和旧生代采用不同的垃圾回收机制. 首先来看一下JVM内存结构,它是由堆.栈.本地方法栈.方法区等部分组成,结构图如下所示. JVM学习笔记 JVM内存管理和JVM垃圾回收 JVM内存组成结构 JVM内存结构由堆.栈.本地方法栈.方法区等部分组成,结构图如下所示: 1)堆 所有通过new创建的对象的内存都在堆中分配,其大小可以通过-Xmx和-Xms来控制.堆

  • 图解Golang的GC垃圾回收算法

    虽然Golang的GC自打一开始,就被人所诟病,但是经过这么多年的发展,Golang的GC已经改善了非常多,变得非常优秀了. 以下是Golang GC算法的里程碑: v1.1 STW v1.3 Mark STW, Sweep 并行 v1.5 三色标记法 v1.8 hybrid write barrier 经典的GC算法有三种: 引用计数(reference counting) . 标记-清扫(mark & sweep) . 复制收集(Copy and Collection) . Golang的G

  • Java中GC的工作原理详细介绍

    Java中GC的工作原理 引子:面试时被问到垃圾回收机制,只是粗略的讲'程序员不能直接对内存操作,jvm负责对已经超过作用域的对象回收处理',面官表情呆滞,也就没再继续深入. 转文: 一个优秀的Java程序员必须了解GC的工作原理.如何优化GC的性能.如何与GC进行有限的交互,有一些应用程序对性能要求较高,例如嵌入式系统.实时系统等,只有全面提升内存的管理效率,才能提高整个应用程序的性能.本文将从GC的工作原理.GC的几个关键问题进行探讨,最后提出一些Java程序设计建议,如何从GC角度提高Ja

  • Python的内存泄漏及gc模块的使用分析

    一般来说在 Python 中,为了解决内存泄漏问题,采用了对象引用计数,并基于引用计数实现自动垃圾回收. 由于Python 有了自动垃圾回收功能,就造成了不少初学者误认为自己从此过上了好日子,不必再受内存泄漏的骚扰了.但如果仔细查看一下Python文档对 __del__() 函数的描述,就知道这种好日子里也是有阴云的.下面摘抄一点文档内容如下: Some common situations that may prevent the reference count of an object fro

  • Java中垃圾回收器GC对吞吐量的影响测试

    在看内存管理术语表的时候偶然发现了"Pig in the Python(注:有点像中文里的贪心不足蛇吞象)"的定义,于是便有了这篇文章.表面上看,这个术语说的是GC不停地将大对象从一个分代提升到另一个分代的情景.这么做就好比巨蟒整个吞食掉它的猎物,以至于它在消化的时候都没办法移动了. 在接下来的这24个小时里我的头脑中充斥着这个令人窒息的巨蟒的画面,挥之不去.正如精神病医生所说的,消除恐惧最好的方法就是说出来.于是便有了这篇文章.不过接下的故事我们要讲的不是蟒蛇,而是GC的调优.我对天

  • 深入学习JAVA GC日志的相关知识

    深入学习JAVA GC日志的相关知识

    GC环境模拟 首先我们给出如下代码用来触发GC public static void main(String[] args) { // 每100毫秒创建100线程,每个线程创建一个1M的对象,即每100ms申请100M堆空间 Executors.newScheduledThreadPool(1).scheduleAtFixedRate(() -> { for (int i = 0; i < 100; i++) { new Thread(() -> { try { // 申请1M byte

  • JVM完全解读之GC日志记录分析

    JVM完全解读之GC日志记录分析

    相信大家在系统学习jvm的时候都会有遇到过这样的问题,散落的jvm知识点知道很多,但是真正在线上环境遇到一些莫名其妙的gc异常时候却无从下手去分析. 关于这块的苦我也表示能够理解,之前光是JVM相关的八股文就整理了许多,但是经常是不知道如何在实战中使用.最近也尝试在模拟一些案例来训练自己的JVM相关知识,本文特意记录下这段调优经历. Java应用的GC评估 可能大多数程序员在开发完某个需求之后,往线上环境一丢,然后就基本不怎么关注后续的变化了.但是是否有考虑过,这些新引入的代码会对原有系统造成的

  • Java虚拟机GC日志分析

    本文研究的主要是Java虚拟机中gc日志的理解问题,具体如下. 一.日志分析 理解GC日志是处理Java虚拟机内存问题的基本技能. 通过在java命令种加入参数来指定对应的gc类型,打印gc日志信息并输出至文件等策略. 1.编写java代码 public class ReferenceCountingGC { public Object instance = null; private static final int ONE_MB = 1024 * 1024; private byte[] b

  • jvm垃圾回收之GC调优工具分析详解

    jvm垃圾回收之GC调优工具分析详解

    进行GC性能调优时, 需要明确了解, 当前的GC行为对系统和用户有多大的影响.有多种监控GC的工具和方法, 本章将逐一介绍常用的工具. JVM 在程序执行的过程中, 提供了GC行为的原生数据.那么, 我们就可以利用这些原生数据来生成各种报告.原生数据(raw data) 包括: 各个内存池的当前使用情况, 各个内存池的总容量, 每次GC暂停的持续时间, GC暂停在各个阶段的持续时间. 可以通过这些数据算出各种指标, 例如: 程序的内存分配率, 提升率等等.本章主要介绍如何获取原生数据. 后续的章

  • JVM完全解读之Metaspace解密源码分析

    概述 metaspace,顾名思义,元数据空间,专门用来存元数据的,它是jdk8里特有的数据结构用来替代perm,这块空间很有自己的特点,前段时间公司这块的问题太多了,主要是因为升级了中间件所致,看到大家讨论来讨论去,看得出很多人对metaspace还是模棱两可,不是很了解它,因此我觉得有必要写篇文章来介绍一下它,解开它神秘的面纱,当我们再次碰到它的相关问题的时候不会再感到束手无策. 通过这篇文章,你将可以了解到 为什么会有metaspace metaspace的组成 metaspace的VM参

  • JVM完全解读之YGC来龙去脉分析

    换了新工作,确实比以前忙多了,从而也搁置了自己兴趣,不过还是想方设法的挤出一点时间把YGC的一些细节实现重新看了几遍,HotSpot里的不少代码写的太纠结,山路十八弯,要理清楚确实需要费点时间. 一次YGC过程主要分成两个步骤:1.查找GC Roots,拷贝所引用的对象到 to 区:2.递归遍历步骤1中对象,并拷贝其所引用的对象到 to 区,当然可能会存在自然晋升,或者因为 to 区空间不足引起的提前晋升的情况: 下面进行分析的是Serial GC,ParNew GC可以理解成并发的Serial

  • PHP中错误与异常的日志记录用法分析

    本文分析了PHP中错误与异常的日志记录用法.分享给大家供大家参考,具体如下: 提到 Nginx + PHP 服务的错误日志,我们通常能想到的有 Nginx 的 access 日志.error 日志以及 PHP 的 error 日志.虽然看起来是个很简单的问题,但里面其实又牵扯到应用配置以及日志记录位置的问题,如果是在 ubuntu 等系统下使用 apt-get 的方式来安装,其自有一套较为合理的的配置文件可用.再者运行的应用程序中的配置也会影响到日志记录的方式及内容. 错误与异常的区别 关于错误

  • 使用JVM常用GC日志打印参数

    使用JVM常用GC日志打印参数

    目录 JVM常用GC日志打印参数 1. PrintGC 2. PrintGCDetails 3. PrintGCTimeStamps 4. PrintGCApplicationStoppedTime 5. PrintGCApplicationConcurrentTime 6. PrintHeapAtGC JVM打印GC日志到文件 JVM常用GC日志打印参数 1. PrintGC 最简单的GC参数. 启用配置:-XX:+PrintGC 日志如下: 根据上面红色方框内的数字1.2.3.4.5说明,1

  • THINKPHP项目开发中的日志记录实例分析

    本文实例讲述了THINKPHP项目开发中的日志记录用法.分享给大家供大家参考.具体方法如下: 1.建立日志表 复制代码 代码如下: CREATE TABLE `logs` (    `id` int(11) NOT NULL auto_increment,    `guid` varchar(100) character set utf8 NOT NULL,    `addtime` timestamp NOT NULL default CURRENT_TIMESTAMP,    `accoun

  • go语言日志记录库简单使用方法实例分析

    本文实例讲述了go语言日志记录库简单使用方法.分享给大家供大家参考.具体实现方法如下: 复制代码 代码如下: package main import (  "fmt"  "log"  "os" ) func main(){  logfile,err := os.OpenFile("/var/golang/jb51.net.log",os.O_RDWR|os.O_CREATE,0);  if err!=nil {   fmt.P

  • Java虚拟机JVM优化实战的过程全记录

    Java虚拟机JVM优化实战的过程全记录

    前言 Java虚拟机是运行所有Java程序的抽象计算机,是Java语言的运行环境,它是Java 最具吸引力的特性之一.Java虚拟机是通过在实际的计算机上仿真模拟各种计算机功能模拟来实现的,通过Java虚拟机,您只要根据JVM规格描述将解释器移植到特定的计算机上,就能保证经过编译的任何Java代码能够在该系统上运行. 最近在看JVM群里有人发了一个GC情况,让人帮忙看优化的,于是我也凑热闹发了出来想让群里的大神们指导优化一下,以下是优化过程记录. 一开始我贴了下面的两张图 jstat看GC记录

随机推荐