【金三银四-JVM系列】CMS收集器与GC日志分析定位问题详解

image.png

CMS收集器实战:
实战开始,准备好了没

构建Spring Boot项目:
image.png

image.png

模拟业务场景代码:

@RestController
public class IndexController {
/***

  • 存big对象
  • @return
    */
    @GetMapping("/put")
    public String process() {
    ArrayList<User> users = queryUsers();
    for (User user:users){
    //TODO 业务操作
    }
    return "ok";
    }
    private ArrayList<User> queryUsers() {
    ArrayList<User> users = new ArrayList<>();
    for (int i = 0; i < 50000; i++) {
    users.add(new User(i, "java2b"));
    }
    return users;
    }
    }

public class User {

private int id;
private String name;
private byte[] data;

public User(int id, String name) {
this.id = id;
this.name = name;
data=new byte[1 * 128 * 1024];
}
}
输出收集器信息:
/***

  • 打印jvm信息
  • @return
    */
    @GetMapping("/info")
    public String info() {
    List<GarbageCollectorMXBean> garbages = ManagementFactory.getGarbageCollectorMXBeans();
    StringBuilder stringBuilder = new StringBuilder();
    for (GarbageCollectorMXBean garbage : garbages) {
    stringBuilder.append("垃圾收集器:名称=" + garbage.getName() + ",收集=" + garbage.getCollectionCount() + ",总花费时间="
    + garbage.getCollectionTime());
    // + ",内存区名称=" + Arrays.deepToString(garbage.getMemoryPoolNames()));
    stringBuilder.append("\r\n");
    }
    MemoryMXBean memory = ManagementFactory.getMemoryMXBean();
    MemoryUsage headMemory = memory.getHeapMemoryUsage();
    long MB = 1024 * 1024;
    stringBuilder.append("head堆:");
    stringBuilder.append("\t初始(M):" + headMemory.getInit() / MB);
    stringBuilder.append("\t最大(上限)(M):" + headMemory.getMax() / MB);
    stringBuilder.append("\t当前(已使用)(M):" + headMemory.getUsed() / MB);
    stringBuilder.append("\t提交的内存(已申请)(M):" + headMemory.getCommitted() / MB);
    stringBuilder.append("\t使用率:" + headMemory.getUsed() * 100 / headMemory.getCommitted() + "%");
    return stringBuilder.toString();
    }

    生成jar包部署到服务器
    image.png

    启动参数:
    java -Xms256m -Xmx256m -verbose:gc -Xloggc:/root/jvm/gc-cms.log -XX:+UseConcMarkSweepGC -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintHeapAtGC -XX:HeapDumpPath=/root/jvm/dump.hprof -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCTimeStamps -XX:+PrintCommandLineFlags -XX:+PrintFlagsFinal -XX:+PrintGCDetails -XX:+UseCMSCompactAtFullCollection -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.port=6666 -Djava.rmi.server.hostname=192.168.0.31 -jar /root/jvm/jvm-web-0.0.1-SNAPSHOT.jar > catalina.out &
    这儿要插播下JVM参数意义.
    JVM参数详解:

JVM参数
含义

-XX:-CMSPrecleaningEnabled
不进行预清理,度过我们之前的文章的都知道,CMS 在并发标记和重新标记的这段时间内,会有一个预清理的工作,而这个通过会尝试5秒之内等待来一次 YGC。以免在后面的重新标记阶段耗费大量时间来标记新生代的对象。

-XX:+UseConcMarkSweepGC
此参数将启动 CMS 回收器。默认新生代是 ParNew,也可以设置 Serial 为新生代收集器。该参数等价于 -Xconcgc。

-XX:ParallelGCThreads
由于是并行处理器,当然也可以指定线程数。默认并发线程数是:(ParallelGCThreads + 3)/ 4)。

-XX:ConcGCThreads
或者 -XX:ParallelCMSThreads ;除了上面设置线程的方式,你也可以通过这个两个参数任意一个手工设定 CMS 并发线程数

-XX:CMSInitiatingOccupancyFraction
由于 CMS 回收器不是独占式的,在垃圾回收的时候应用程序仍在工作,所以需要留出足够的内存给应用程序,否则会触发 FGC。而什么时候运行 CMS GC 呢?通过该参数即可设置,该参数表示的是老年代的内存使用百分比。当达到这个阈值就会执行 CMS。默认是68。 如果老年代内存增长很快,建议降低阈值,避免 FGC,如果增长慢,则可以加大阈值,减少 CMS GC 次数。提高吞吐量。

-XX:+UseCMSCompactAtFullCollection
由于 CMS 使用标记清理算法,内存碎片无法避免。该参数指定每次 CMS 后进行一次碎片整理。

-XX:CMSFullGCsBeforeCompaction
由于每次进行碎片整理将会影响性能,你可以使用该参数设定多少次 CMS 后才进行一次碎片整理,也就是内存压缩。

-XX:+CMSClassUnloadingEnabled
允许对类元数据进行回收。

-XX:CMSInitiatingPermOccupancyFraction
当永久区占用率达到这一百分比时,启动 CMS 回收(前提是 -XX:+CMSClassUnloadingEnabled 激活了)。

-XX:UseCMSInitiatingOccupancyOnly
表示只在到达阈值的时候才进行 CMS 回收。

XX:CMSWaitDuration=2000
由于CMS GC 条件比较简单,JVM有一个线程定时扫描Old区,时间间隔可以通过该参数指定(毫秒单位),默认是2s。

JVM工具参数:

JVM参数
含义

-XX:+PrintGCDateStamps
打印 GC 日志时间戳

-XX:+PrintGCDetails
打印 GC 详情

-XX:+PrintGCTimeStamps
印此次垃圾回收距离jvm开始运行的所耗时间

-Xloggc:
将垃圾回收信息输出到指定文件

-verbose:gc
打印 GC 日志

-XX:+PrintGCApplicationStopedTime
查看 gc 造成的应用暂停时间

XX:+PrintTenuringDistribution
对象晋升的日志

-XX:+HeapDumpOnOutOfMemoryError
内存溢出时输出 dump 文件

启动效果:[图片上传中...(image.png-cbc57a-1578570254235-0)]

访问:

我们不难发现新生代用的是parNew 老年代用的cms
image.png

请求put:
我们通过http访问put方法之后看看效果:

效果如下:
image.png

image.png
image.png

image.png

在运行的过程中我们发现有大量的对象进入老年代,触发了full gc,cms一直在收集。

使用率达到99%,cms也一刻没停下:
image.png

日志分析:
image.png

日志分析1.0版本:
我们抽取一条日志来分析下

[GC (Allocation Failure) 0K->63K(64K), 0.0047147 secs] 10258K->6780K(46144K), [Metaspace: 3434K->3434K(1056768K)], 0.0047613 secs][Times: user=0.02 sys=0.00, real=0.00 secs]
该日志为四个部分:
Full GC:
表明进行了一次垃圾回收,前面没有Full修饰,表明这是一次Minor GC ,注意它不表示只GC新生代,并且现有的不管是新生代还是老年代都会STW。
Allocation Failure:
表明本次引起GC的原因是因为在年轻代中没有足够的空间能够存储新的数据了。
10258K->6780K(46144K),:单位是KB
三个参数分别为:GC前该内存区域(这里是年轻代)使用容量,GC后该内存区域使用容量,该内存区域总容量。
0.0047613 secs:
该内存区域GC耗时,单位是秒
[Times: user=0.04 sys=0.00, real=0.01 secs]:
分别表示用户态耗时,内核态耗时和总耗时

image.png

日志分析2.0版本:

采用在线gceasy来进行分析,我们打开网址,然后上传我们生产的gc日志,如图所示:
image.png

优化问题:

列出了可以优化的4个问题新生代和老年代元空间内存占用情况
image.png

吞吐量统计:97.39%
image.png

各各分代的内存变化:
image.png

CMS垃圾收集器不同时期发生的耗时
image.png

image.png

GC发生次数的分类和耗时情况
image.png

定位问题:

我们通过生产的快照文件来定位问题:
image.png
image.png

JProfiler:
下载到本地通过JProfiler打开查看
image.png

查看大对象:
image.png

我们不难发现是ArrayList集合占用了96%的内存,那我们来看看哪块代码大量用到了我们ArrayList集合了?
image.png

找到对应代码


image.png

通过此代码我们就发现put方法大量用到了ArrayList集合造成的内存溢出OOM

总结:上述实战相信大家都明白了,大致流程就是:
1、够将SpringBoot项目 模拟真实大批量用户场景
2、配置JVM参数然后部署运行监控数据生成日志文件
3、通过分析日志文件确认问题。
需要上文代码和软件的朋友,可以关注我的微信:Java2B,大家可以自己实操下加深印象。
今天就写到这了。觉得不错欢迎关注点赞,你们的点赞关注是我出好文最大的动力。
能看到这的都是牛人,麻烦帮忙点个赞关注下,下篇我继续带来CMS和G1实战PK对比,图形化对比看的更直观。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 213,928评论 6 493
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 91,192评论 3 387
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 159,468评论 0 349
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 57,186评论 1 286
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 66,295评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,374评论 1 292
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,403评论 3 412
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,186评论 0 269
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,610评论 1 306
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,906评论 2 328
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,075评论 1 341
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,755评论 4 337
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,393评论 3 320
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,079评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,313评论 1 267
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,934评论 2 365
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,963评论 2 351

推荐阅读更多精彩内容