时间戳

首页 > 解决方案 > openjdk zgc上cpu使用率高

java - openjdk zgc上cpu使用率高

问题描述

我试图在产品环境中使用zgc，所以我将jdk从jdk8更新到openjdk 15，tomcat 8到tomcat 8.5，以及gc相关选项，但是在jvm启动几个小时后cpu使用率达到1000+% （正常的 cpu 使用率应该是 100-300%）。有时，当cpu很高时，日志文件中有很多ICBufferFull安全点：

[2020-11-12T19:00:43.669+0800] Safepoint "ICBufferFull", Time since last: 41374119 ns, Reaching safepoint: 2026134 ns, At safepoint: 85993 ns, Total: 2112127 ns
[2020-11-12T19:00:43.672+0800] Safepoint "ICBufferFull", Time since last: 2521598 ns, Reaching safepoint: 1109894 ns, At safepoint: 57235 ns, Total: 1167129 ns
[2020-11-12T19:00:43.676+0800] Safepoint "ICBufferFull", Time since last: 2892867 ns, Reaching safepoint: 1240834 ns, At safepoint: 59633 ns, Total: 1300467 ns
[2020-11-12T19:00:43.681+0800] Safepoint "ICBufferFull", Time since last: 2870110 ns, Reaching safepoint: 1425837 ns, At safepoint: 54052 ns, Total: 1479889 ns

如果让节点离线大约 30 秒，cpu 会下降，然后使其在线，它将正常工作几个小时，直到 cpu 再次变高。我检查了源代码， ICBufferFull 表示“内联缓存缓冲区已满”，但我找不到增加它的选项，有人可以帮忙吗？谢谢！

gc 选项是：

export JAVA_OPTS='-Xms10g -Xmx10g -XX:+UseLargePages -XX:ZAllocationSpikeTolerance=5 -XX:ParallelGCThreads=8 -XX:ConcGCThreads=4 -Xss2m -XX:+UseZGC -Xlog:gc,gc+phases,safepoint:file=/logs/gc.log:t:filecount=10,filesize=10m -XX:+HeapDumpOnOutOfMemoryError'

编辑1：

我有另一台主机运行良好，仍然在 jdk8 中运行，以 cms 为参考，对 2 台主机的请求几乎相同。

我用 async-profile 对其进行了分析，最热的方法是java/lang/ThreadLocal$ThreadLocalMap.getEntryAfterMiss，出现了 50+%，最热的原生方法是ZMark::try_mark_object(ZMarkCache*, unsigned long, bool)，仅出现了 0.41%。我查看了jdk8和openjdk15中的线程本地相关源码，好像没有变。

编辑2：

我在JIRA上发现了一个类似的错误，我的应用程序也是 lucene 相关的，并且从 gc 日志中，当弱引用计数为 1m+ 时，使用率很高。所以问题是如何在 zgc 中更积极地收集弱引用？

编辑3：

从以下每 3 秒调用一次 System.gc() 的日志来看，我的应用程序似乎产生了太多的弱引用。但奇怪的是生产的数量在开始后不断增加。从 11:00 到 17:00，请求几乎不变。请注意，在 GC(9821) 之后，cpu 自动从 600% 下降到 400%，入队人数约为 250K。GC(10265) 节点离线，入队约为 770K。为什么入队的数量在很长一段时间内都很小，这是否意味着对象没有被完全回收？

[2020-11-19T11:00:00.245+0800] GC(992) Weak: 155658 encountered, 72334 discovered, 0 enqueued
[2020-11-19T12:00:00.397+0800] GC(2194) Weak: 220462 encountered, 122216 discovered, 1380 enqueued
[2020-11-19T12:00:03.411+0800] GC(2195) Weak: 220598 encountered, 107228 discovered, 677 enqueued
[2020-11-19T13:00:00.497+0800] GC(3395) Weak: 222536 encountered, 82199 discovered, 1713 enqueued
[2020-11-19T14:00:00.647+0800] GC(4613) Weak: 443946 encountered, 291651 discovered, 292 enqueued
[2020-11-19T15:00:01.173+0800] GC(5819) Weak: 338065 encountered, 124351 discovered, 815 enqueued
[2020-11-19T16:00:01.283+0800] GC(7022) Weak: 459070 encountered, 298932 discovered, 353 enqueued
[2020-11-19T17:00:01.426+0800] GC(8222) Weak: 688162 encountered, 519369 discovered, 4648 enqueued
[2020-11-19T16:00:01.283+0800] GC(7022) Weak: 459070 encountered, 298932 discovered, 353 enqueued
[2020-11-19T17:00:01.426+0800] GC(8222) Weak: 688162 encountered, 519369 discovered, 4648 enqueued
[2020-11-19T18:00:01.556+0800] GC(9430) Weak: 1078757 encountered, 928748 discovered, 1691 enqueued
[2020-11-19T18:18:43.595+0800] GC(9821) Weak: 1022080 encountered, 841168 discovered, 247352 enqueued
[2020-11-19T18:18:46.592+0800] GC(9822) Weak: 774253 encountered, 568564 discovered, 3938 enqueued
[2020-11-19T18:40:49.616+0800] GC(10265) Weak: 842081 encountered, 788825 discovered, 767288 enqueued
[2020-11-19T18:40:52.593+0800] GC(10266) Weak: 74876 encountered, 18186 discovered, 1 enqueued

标签： javajvmzgc

解决方案

现代 GC 延迟了对弱可达对象的收集。

由总是处理弱可达对象触发的System.gc()集合，默认情况下是并发的，因此您可以实现一个调用该方法的周期性任务。

推荐阅读