频繁GC (Allocation Failure)

💬 StarRocks 用户问答
#1

【详述】
每2~3秒就报一次GC (Allocation Failure)：
2022-07-01T09:44:04.860+0800: 64185.135: [GC (Allocation Failure) 2022-07-01T09:44:04.860+0800: 64185.135: [ParNew: 549826K->305K(618048K), 0.0067484 secs] 754309K->204791K(1991616K), 0.0069203 secs] [Times: user=0.11 sys=0.01, real=0.00 secs]
2022-07-01T09:44:07.418+0800: 64187.694: [GC (Allocation Failure) 2022-07-01T09:44:07.418+0800: 64187.694: [ParNew: 549681K->155K(618048K), 0.0063818 secs] 754167K->204641K(1991616K), 0.0065560 secs] [Times: user=0.09 sys=0.00, real=0.00 secs]
2022-07-01T09:44:09.984+0800: 64190.260: [GC (Allocation Failure) 2022-07-01T09:44:09.984+0800: 64190.260: [ParNew: 549531K->171K(618048K), 0.0070545 secs] 754017K->204659K(1991616K), 0.0072065 secs] [Times: user=0.12 sys=0.00, real=0.01 secs]
2022-07-01T09:44:12.546+0800: 64192.822: [GC (Allocation Failure) 2022-07-01T09:44:12.547+0800: 64192.822: [ParNew: 549547K->164K(618048K), 0.0074844 secs] 754035K->204652K(1991616K), 0.0076735 secs] [Times: user=0.09 sys=0.00, real=0.01 secs]
2022-07-01T09:44:15.113+0800: 64195.389: [GC (Allocation Failure) 2022-07-01T09:44:15.113+0800: 64195.389: [ParNew: 549540K->140K(618048K), 0.0063394 secs] 754028K->204631K(1991616K), 0.0065212 secs] [Times: user=0.12 sys=0.00, real=0.01 secs]
2022-07-01T09:44:17.676+0800: 64197.952: [GC (Allocation Failure) 2022-07-01T09:44:17.676+0800: 64197.952: [ParNew: 549516K->139K(618048K), 0.0073254 secs] 754007K->204630K(1991616K), 0.0074881 secs] [Times: user=0.12 sys=0.01, real=0.01 secs]
【背景】做过哪些操作？
将fe.conf中的JAVA_OPTS调整为16G：
JAVA_OPTS="-Dlog4j2.formatMsgNoLookups=true -Xmx16384m -XX:+UseMembar -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=7 -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+CMSClassUnloadingEnabled -XX:-CMSParallelRemarkEnabled -XX:CMSInitiatingOccupancyFraction=80 -XX:SoftRefLRUPolicyMSPerMB=0 -Xloggc:$STARROCKS_HOME/log/fe.gc.log.$DATE"
【业务影响】
【StarRocks版本】
2.2.2、2.0GA
【集群规模】
3fe（3 follower）+3be（fe与be混部）

【附件】
fe.gc.log.20220630-155419 (3.6 MB)

#2

是新安装的StarRocks集群，还没有任何查询压力

#3

这是正常的日志，不是gc的。建议咱们装一个监控来观察集群的使用情况。
https://docs.starrocks.com/zh-cn/main/administration/Monitor_and_Alert#使用prometheusgrafana
https://blog.csdn.net/Acer12138/article/details/125529210?csdn_share_tail={"type"%3A"blog"%2C"rType"%3A"article"%2C"rId"%3A"125529210"%2C"source"%3A"Acer12138"}&ctrtid=NK5eO

#4

我觉得不正常，Eden区是2.5G的大小，差不多5~10秒都被沾满了，就触发一次YGC，况且，目前集群没啥查询：
[root@bigdata-1 log]# jstat -gcutil 10747 1000
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
0.00 0.03 55.99 1.24 95.27 90.47 5183 123.086 4 0.633 123.718
0.00 0.03 65.99 1.24 95.27 90.47 5183 123.086 4 0.633 123.718
0.00 0.03 75.99 1.24 95.27 90.47 5183 123.086 4 0.633 123.718
0.00 0.03 85.99 1.24 95.27 90.47 5183 123.086 4 0.633 123.718
0.00 0.03 95.99 1.24 95.27 90.47 5183 123.086 4 0.633 123.718
0.03 0.00 6.00 1.24 95.27 90.47 5184 123.105 4 0.633 123.737
0.03 0.00 16.02 1.24 95.27 90.47 5184 123.105 4 0.633 123.737
0.03 0.00 26.02 1.24 95.27 90.47 5184 123.105 4 0.633 123.737
0.03 0.00 36.02 1.24 95.27 90.47 5184 123.105 4 0.633 123.737
0.03 0.00 46.02 1.24 95.27 90.47 5184 123.105 4 0.633 123.737
0.03 0.00 56.02 1.24 95.27 90.47 5184 123.105 4 0.633 123.737
0.03 0.00 66.02 1.24 95.27 90.47 5184 123.105 4 0.633 123.737
0.03 0.00 76.02 1.24 95.27 90.47 5184 123.105 4 0.633 123.737
0.03 0.00 86.02 1.24 95.27 90.47 5184 123.105 4 0.633 123.737
0.03 0.00 94.02 1.24 95.27 90.47 5184 123.105 4 0.633 123.737
0.00 0.03 3.97 1.24 95.27 90.47 5185 123.129 4 0.633 123.762

#5

企业微信截图_20220702095842
企业微信截图_202207020958421298×800 19.9 KB

#6

一直是什么在产生新对象，差不多10秒钟，就有2.5G，而且一旦gc，几乎全部是垃圾，会被回收掉

#7

[root@bigdata-1 log]# jmap -histo 10747 | head -20

num #instances #bytes class name

1: 84609022 2090925136 [B
2: 311738 30751008 [C
3: 5601 22501936 [I
4: 42600 16257512 [Ljava.lang.Object;
5: 281 9212304 [Ljava.util.concurrent.ForkJoinTask;
6: 173180 8312640 com.sun.tools.javac.file.ZipFileIndex$Entry
7: 311749 7481976 java.lang.String
8: 11040 7418880 io.netty.util.internal.shaded.org.jctools.queues.MpscArrayQueue
9: 19938 1754544 com.starrocks.analysis.SlotRef
10: 384 1558608 [Ljava.nio.ByteBuffer;
11: 47656 1524992 java.util.HashMap$Node
12: 60763 1458312 java.util.ArrayList
13: 406 1384112 [Ljava.nio.channels.SelectionKey;
14: 24497 1331712 [S
15: 11720 1306016 java.lang.Class
16: 32403 1296120 java.lang.ref.SoftReference
17: 17923 1110400 [Ljava.util.HashMap$Node;

#8

YGC我理解这个频率其实还好。我理解

京ICP备2022026421号-1