大概是这样的

写这篇文章的意图是由于线上服务出现了接口调用超时的问题。该服务在架构中处于业务网关，主要处理图文等业务的转发能力。从监控大盘中，可以看到服务器的GC相当频繁，接口超时的情况同GC的波动也在波动曲线中几乎也保持相同。按道理，仅仅是服务转发，不应该有很频繁的GC。服务器的配置为4C8G，单台服务的QPS差不多400左右。

排查此类问题可以通过开启G1垃圾收集器的跟踪和诊断开关获取GC日志，通过PrintGCDetails可以获取最详细的GC日志。 我们也可以通过开启UnlockDiagnositcVMOptions和G1PrintRegionLivenessInfo参数，可以在标记周期最后打印每个分区(Region)的占用情况和存活对象占用空间，G1PrintHeapRegions可以打印分区的分配和回收信息。

G1 GC是一个响应时间优先的GC算法，它与CMS最大的不同是，用户可以设定整个GC过程的期望停顿时间，参数-XX:MaxGCPauseMillis指定一个G1收集过程目标停顿时间，默认值200ms，不过它不是硬性条件，只是期望值。那么G1怎么满足用户的期望呢？就需要这个停顿预测模型了。G1根据这个模型统计计算出来的历史数据来预测本次收集需要选择的Region数量，从而尽量满足用户设定的目标停顿时间。

JVM配置参数解释

JVM设置如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
-server
-Xmx6g
-Xms6g
-Djava.util.concurrent.ForkJoinPool.common.parallelism=4
-Dfile.encoding=UTF-8
-Dfastjson.parser.safeMode=true
-Xss256kb
-XX:+AlwaysPreTouch
-XX:CICompilerCount=3
-XX:ConcGCThreads=4
-XX:+UnlockDiagnosticVMOptions
-XX:+UnlockExperimentalVMOptions
-XX:G1MixedGCLiveThresholdPercent=65
-XX:G1OldCSetRegionThresholdPercent=3
-XX:+G1PrintRegionLivenessInfo
-XX:G1ReservePercent=10
-XX:+G1TraceConcRefinement
-XX:GCLogFileSize=10m
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/home/admin/output/demo
-XX:InitialTenuringThreshold=3
-XX:InitiatingHeapOccupancyPercent=30
-XX:+ManagementServer
-XX:MaxGCPauseMillis=100
-XX:MaxMetaspaceSize=512m
-XX:MaxTenuringThreshold=3
-XX:NativeMemoryTracking=detail
-XX:NumberOfGCLogFiles=10
-XX:-OmitStackTraceInFastThrow
-XX:ParallelGCThreads=4
-verbose:gc 
-XX:+PrintGC
-XX:+PrintGCApplicationConcurrentTime
-XX:+PrintGCApplicationStoppedTime
-XX:+PrintGCDateStamps
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-XX:+PrintJNIGCStalls
-XX:+PrintNMTStatistics
-XX:ThreadStackSize=256
-XX:G1HeapRegionSize=4m
-XX:G1HeapWastePercent=10
-XX:G1MaxNewSizePercent=70
-XX:G1NewSizePercent=45
-XX:+UseCompressedClassPointers
-XX:+UseCompressedOops
-XX:+UseFastUnorderedTimeStamps
-XX:+UseG1GC
-XX:+UseGCLogFileRotation
-XX:+UseLargePages
-XX:+UseStringDeduplication
-XX:+G1PrintHeapRegions
-Xloggc:gc.log

选项/默认值 说明
-Xmx6g
-Xms6g
-Djava.util.concurrent.ForkJoinPool.common.parallelism=4 指定ForkJoinPool的parallelism参数。通过代码指定，必须得在commonPool初始化之前（parallel的stream被调用之前，一般可在系统启动后设置）注入进去，否则无法生效。通过启动参数指定无此限制，较为安全。
-Dfastjson.parser.safeMode=true fastjson序列化开启安全模式。
-Xss256kb 线程栈256
-XX:+AlwaysPreTouch
-XX:CICompilerCount=3
-XX:ConcGCThreads=4 并发垃圾收集器使用的线程数量。默认值随JVM运行的平台不同而不同。
-XX:+UnlockDiagnosticVMOptions
-XX:+UnlockExperimentalVMOptions
-XX:G1MixedGCLiveThresholdPercent=65
-XX:G1OldCSetRegionThresholdPercent=3
-XX:+G1PrintRegionLivenessInfo
-XX:G1ReservePercent=10 设置堆内存保留为假天花板的总量，以降低提升失败的可能性.。默认值是 10。
-XX:+G1TraceConcRefinement
-XX:GCLogFileSize=10m
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/home/admin/output/demo
-XX:InitialTenuringThreshold=3
-XX:InitiatingHeapOccupancyPercent=n 启动并发GC周期时的堆内存占用百分比。G1之类的垃圾收集器用它来触发并发GC周期,基于整个堆的使用率，而不只是某一代内存的使用比。值为 0 则表示”一直执行GC循环”。默认值为 45。
-XX:+ManagementServer
-XX:MaxGCPauseMillis=n 设置最大GC停顿时间(GC pause time)指标(target)。这是一个软性指标(soft goal)，JVM 会尽量去达成这个目标。
-XX:MaxMetaspaceSize=512m
-XX:MaxTenuringThreshold=3 提升年老代的最大临界值(tenuring threshold)。默认值为 15。
-XX:NativeMemoryTracking=detail
-XX:NumberOfGCLogFiles=10
-XX:-OmitStackTraceInFastThrow
-XX:ParallelGCThreads=4 设置垃圾收集器在并行阶段使用的线程数，默认值随JVM运行的平台不同而不同。
-verbose:gc
-XX:+PrintGC
-XX:+PrintGCApplicationConcurrentTime
-XX:+PrintGCApplicationStoppedTime
-XX:+PrintGCDateStamps
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-XX:+PrintJNIGCStalls
-XX:+PrintNMTStatistics
-XX:ThreadStackSize=256
-XX:G1HeapRegionSize=4m 使用G1时Java堆会被分为大小统一的的区(region)。此参数可以指定每个heap区的大小. 默认值将根据 heap size 算出最优解。最小值为 1Mb，最大值为 32Mb。
-XX:G1HeapWastePercent=10
-XX:G1MaxNewSizePercent=70
-XX:G1NewSizePercent=45
-XX:+UseCompressedClassPointers
-XX:+UseCompressedOops
-XX:+UseFastUnorderedTimeStamps
-XX:+UseG1GC 使用 G1 (Garbage First) 垃圾收集器
-XX:+UseGCLogFileRotation
-XX:+UseLargePages
-XX:+UseStringDeduplication
-XX:+G1PrintHeapRegions
-Xloggc:gc.log
-XX:NewRatio=n 新生代与老生代(new/old generation)的大小比例(Ratio)。 默认值为 2.
-XX:SurvivorRatio=n eden/survivor 空间大小的比例(Ratio)，默认值为 8。 
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
2022-04-13T20:04:05.983+0800: 1728092.262: Total time for which application threads were stopped: 0.0174379 seconds, Stopping threads took: 0.0000980 seconds
2022-04-13T20:04:10.395+0800: 1728096.673: Total time for which application threads were stopped: 0.0054102 seconds, Stopping threads took: 0.0001913 seconds
1728096.682: Setting _needs_gc. Thread "VM Thread" 1 locked.
2022-04-13T20:04:10.403+0800: 1728096.682: Total time for which application threads were stopped: 0.0052978 seconds, Stopping threads took: 0.0002709 seconds
1728096.682: Thread "GelfSenderThread" is performing GC after exiting critical section, 0 locked
1728096.682: Allocation failed. Thread "wordsearch-Thread-7" is stalled by JNI critical section, 0 locked.
2022-04-13T20:04:10.409+0800: 1728096.687: [GC pause (GCLocker Initiated GC) (young), 0.0191576 secs]
   [Parallel Time: 11.5 ms, GC Workers: 4]
      [GC Worker Start (ms): Min: 1728096687.7, Avg: 1728096687.7, Max: 1728096687.8, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 3.0, Avg: 3.3, Max: 4.0, Diff: 1.0, Sum: 13.1]
      [Update RS (ms): Min: 2.3, Avg: 3.0, Max: 3.2, Diff: 0.9, Sum: 11.9]
         [Processed Buffers: Min: 21, Avg: 31.5, Max: 49, Diff: 28, Sum: 126]
      [Scan RS (ms): Min: 0.2, Avg: 0.2, Max: 0.2, Diff: 0.0, Sum: 0.9]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 4.8, Avg: 4.9, Max: 5.1, Diff: 0.3, Sum: 19.6]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Termination Attempts: Min: 2, Avg: 3.5, Max: 6, Diff: 4, Sum: 14]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.3]
      [GC Worker Total (ms): Min: 11.4, Avg: 11.5, Max: 11.5, Diff: 0.0, Sum: 45.8]
      [GC Worker End (ms): Min: 1728096699.2, Avg: 1728096699.2, Max: 1728096699.2, Diff: 0.0]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.3 ms]
   [Other: 7.3 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 5.0 ms]
      [Ref Enq: 0.1 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.2 ms]
      [Free CSet: 0.9 ms]
   [Eden: 1388.0M(1388.0M)->0.0B(1388.0M) Survivors: 6144.0K->6144.0K Heap: 5509.1M(6144.0M)->4120.3M(6144.0M)]
 [Times: user=0.05 sys=0.00, real=0.02 secs] 


2022-04-13T20:04:10.428+0800: 1728096.707: Total time for which application threads were stopped: 0.0248409 seconds, Stopping threads took: 0.0002429 seconds
2022-04-13T20:04:15.393+0800: 1728101.671: Total time for which application threads were stopped: 0.0051294 seconds, Stopping threads took: 0.0001996 seconds
1728102.188: Setting _needs_gc. Thread "VM Thread" 1 locked.
2022-04-13T20:04:15.910+0800: 1728102.188: Total time for which application threads were stopped: 0.0052083 seconds, Stopping threads took: 0.0002159 seconds
1728102.188: Thread "GelfSenderThread" is performing GC after exiting critical section, 0 locked
2022-04-13T20:04:15.915+0800: 1728102.193: [GC pause (GCLocker Initiated GC) (young) (initial-mark), 0.0203515 secs]
   [Parallel Time: 12.3 ms, GC Workers: 4]
      [GC Worker Start (ms): Min: 1728102194.0, Avg: 1728102194.0, Max: 1728102194.0, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 3.6, Avg: 3.8, Max: 4.1, Diff: 0.6, Sum: 15.2]
      [Update RS (ms): Min: 3.2, Avg: 3.6, Max: 3.8, Diff: 0.6, Sum: 14.3]
         [Processed Buffers: Min: 9, Avg: 34.0, Max: 60, Diff: 51, Sum: 136]
      [Scan RS (ms): Min: 0.2, Avg: 0.2, Max: 0.2, Diff: 0.0, Sum: 0.8]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 4.3, Avg: 4.4, Max: 4.6, Diff: 0.3, Sum: 17.5]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Termination Attempts: Min: 1, Avg: 3.0, Max: 5, Diff: 4, Sum: 12]
      [GC Worker Other (ms): Min: 0.1, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.3]
      [GC Worker Total (ms): Min: 12.0, Avg: 12.0, Max: 12.0, Diff: 0.1, Sum: 48.1]
      [GC Worker End (ms): Min: 1728102206.0, Avg: 1728102206.0, Max: 1728102206.1, Diff: 0.0]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 7.8 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 5.5 ms]
      [Ref Enq: 0.1 ms]
      [Redirty Cards: 0.0 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.8 ms]
   [Eden: 1390.0M(1388.0M)->0.0B(1384.0M) Survivors: 6144.0K->8192.0K Heap: 5509.4M(6144.0M)->4122.8M(6144.0M)]
 [Times: user=0.05 sys=0.00, real=0.02 secs] 
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
2022-04-18T17:08:06.722+0800: 5.254: Total time for which application threads were stopped: 0.0005588 seconds, Stopping threads took: 0.0001933 seconds
2022-04-18T17:08:06.888+0800: 5.420: Total time for which application threads were stopped: 0.0002737 seconds, Stopping threads took: 0.0000595 seconds
2022-04-18T17:08:07.010+0800: 5.542: Total time for which application threads were stopped: 0.0004168 seconds, Stopping threads took: 0.0001236 seconds
2022-04-18T17:08:07.081+0800: 5.613: Total time for which application threads were stopped: 0.0003357 seconds, Stopping threads took: 0.0000465 seconds
2022-04-18T17:08:07.102+0800: 5.634: Total time for which application threads were stopped: 0.0003028 seconds, Stopping threads took: 0.0000488 seconds
2022-04-18T17:08:08.102+0800: 6.634: Total time for which application threads were stopped: 0.0001207 seconds, Stopping threads took: 0.0000415 seconds
2022-04-18T17:08:11.159+0800: 9.691: Total time for which application threads were stopped: 0.0004656 seconds, Stopping threads took: 0.0000253 seconds
2022-04-18T17:08:26.524+0800: 25.056: Total time for which application threads were stopped: 0.0003781 seconds, Stopping threads took: 0.0000961 seconds
2022-04-18T17:08:26.637+0800: 25.169: Total time for which application threads were stopped: 0.0004358 seconds, Stopping threads took: 0.0000430 seconds
2022-04-18T17:08:26.806+0800: 25.338: Total time for which application threads were stopped: 0.0003477 seconds, Stopping threads took: 0.0001887 seconds
2022-04-18T17:08:26.807+0800: 25.339: Total time for which application threads were stopped: 0.0001098 seconds, Stopping threads took: 0.0000438 seconds
2022-04-18T17:08:26.807+0800: 25.339: Total time for which application threads were stopped: 0.0001529 seconds, Stopping threads took: 0.0000599 seconds
2022-04-18T17:08:26.807+0800: 25.339: Total time for which application threads were stopped: 0.0000829 seconds, Stopping threads took: 0.0000235 seconds
2022-04-18T17:08:26.808+0800: 25.340: Total time for which application threads were stopped: 0.0001200 seconds, Stopping threads took: 0.0000718 seconds
2022-04-18T17:08:26.808+0800: 25.340: Total time for which application threads were stopped: 0.0000966 seconds, Stopping threads took: 0.0000302 seconds
2022-04-18T17:08:26.808+0800: 25.340: Total time for which application threads were stopped: 0.0000921 seconds, Stopping threads took: 0.0000513 seconds
2022-04-18T17:08:26.809+0800: 25.340: Total time for which application threads were stopped: 0.0001031 seconds, Stopping threads took: 0.0000393 seconds
2022-04-18T17:08:26.809+0800: 25.341: Total time for which application threads were stopped: 0.0001491 seconds, Stopping threads took: 0.0000582 seconds
2022-04-18T17:08:26.809+0800: 25.341: Total time for which application threads were stopped: 0.0002091 seconds, Stopping threads took: 0.0001478 seconds
2022-04-18T17:08:26.812+0800: 25.344: Total time for which application threads were stopped: 0.0007559 seconds, Stopping threads took: 0.0005915 seconds
2022-04-18T17:08:26.823+0800: 25.355: Total time for which application threads were stopped: 0.0001358 seconds, Stopping threads took: 0.0000439 seconds
2022-04-18T17:08:26.839+0800: 25.371: Total time for which application threads were stopped: 0.0001612 seconds, Stopping threads took: 0.0000442 seconds
2022-04-18T17:08:26.854+0800: 25.385: Total time for which application threads were stopped: 0.0001410 seconds, Stopping threads took: 0.0000422 seconds
2022-04-18T17:08:26.862+0800: 25.394: Total time for which application threads were stopped: 0.0001832 seconds, Stopping threads took: 0.0000967 seconds
2022-04-18T17:08:26.865+0800: 25.397: [GC pause (Metadata GC Threshold) (young) (initial-mark), 0.0437982 secs]
   [Parallel Time: 13.9 ms, GC Workers: 4]
      [GC Worker Start (ms): Min: 25402.4, Avg: 25402.5, Max: 25402.5, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 2.0, Avg: 2.9, Max: 3.9, Diff: 1.9, Sum: 11.6]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.5, Max: 1.3, Diff: 1.3, Sum: 1.9]
      [Object Copy (ms): Min: 9.4, Avg: 10.2, Max: 11.2, Diff: 1.8, Sum: 41.0]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Termination Attempts: Min: 1, Avg: 2.0, Max: 3, Diff: 2, Sum: 8]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 13.6, Avg: 13.7, Max: 13.7, Diff: 0.1, Sum: 54.7]
      [GC Worker End (ms): Min: 25416.2, Avg: 25416.2, Max: 25416.2, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 29.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 22.5 ms]
      [Ref Enq: 0.1 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.4 ms]
   [Eden: 200.0M(306.0M)->0.0B(288.0M) Survivors: 0.0B->18.0M Heap: 199.0M(6144.0M)->16.9M(6144.0M)]
 [Times: user=0.07 sys=0.03, real=0.05 secs] 
2022-04-18T17:08:26.909+0800: 25.441: [GC concurrent-root-region-scan-start]
2022-04-18T17:08:26.909+0800: 25.441: Total time for which application threads were stopped: 0.0442574 seconds, Stopping threads took: 0.0000569 seconds
2022-04-18T17:08:26.915+0800: 25.447: [GC concurrent-root-region-scan-end, 0.0059254 secs]
2022-04-18T17:08:26.915+0800: 25.447: [GC concurrent-mark-start]
2022-04-18T17:08:26.916+0800: 25.448: [GC concurrent-mark-end, 0.0009580 secs]
2022-04-18T17:08:26.916+0800: 25.448: [GC remark 2022-04-18T17:08:26.916+0800: 25.448: [Finalize Marking, 0.0004089 secs] 2022-04-18T17:08:26.916+0800: 25.448: [GC ref-proc, 0.0001182 secs] 2022-04-18T17:08:26.916+0800: 25.448: [Unloading, 0.0076554 secs], 0.0089764 secs]
 [Times: user=0.03 sys=0.01, real=0.00 secs] 
2022-04-18T17:08:26.925+0800: 25.457: Total time for which application threads were stopped: 0.0091996 seconds, Stopping threads took: 0.0000800 seconds
2022-04-18T17:08:26.925+0800: 25.457: [GC cleanup 18M->18M(6144M), 0.0032182 secs]
 [Times: user=0.01 sys=0.01, real=0.01 secs] 
2022-04-18T17:08:26.928+0800: 25.460: Total time for which application threads were stopped: 0.0034375 seconds, Stopping threads took: 0.0000612 seconds
2022-04-18T17:08:26.931+0800: 25.463: Total time for which application threads were stopped: 0.0001478 seconds, Stopping threads took: 0.0000591 seconds
2022-04-18T17:08:26.932+0800: 25.464: Total time for which application threads were stopped: 0.0001036 seconds, Stopping threads took: 0.0000731 seconds
2022-04-18T17:08:26.984+0800: 25.515: Total time for which application threads were stopped: 0.0001361 seconds, Stopping threads took: 0.0000446 seconds
2022-04-18T17:08:26.984+0800: 25.516: Total time for which application threads were stopped: 0.0000370 seconds, Stopping threads took: 0.0000151 seconds
2022-04-18T17:08:26.991+0800: 25.523: Total time for which application threads were stopped: 0.0001324 seconds, Stopping threads took: 0.0000417 seconds
2022-04-18T17:08:26.991+0800: 25.523: Total time for which application threads were stopped: 0.0000401 seconds, Stopping threads took: 0.0000151 seconds
2022-04-18T17:08:26.992+0800: 25.523: Total time for which application threads were stopped: 0.0000421 seconds, Stopping threads took: 0.0000137 seconds
2022-04-18T17:08:27.000+0800: 25.532: Total time for which application threads were stopped: 0.0004460 seconds, Stopping threads took: 0.0000411 seconds
2022-04-18T17:08:27.002+0800: 25.534: Total time for which application threads were stopped: 0.0000773 seconds, Stopping threads took: 0.0000247 seconds
2022-04-18T17:08:28.002+0800: 26.534: Total time for which application threads were stopped: 0.0001755 seconds, Stopping threads took: 0.0000632 seconds
2022-04-18T17:08:36.233+0800: 34.765: Total time for which application threads were stopped: 0.0001776 seconds, Stopping threads took: 0.0000476 seconds
2022-04-18T17:08:36.233+0800: 34.765: Total time for which application threads were stopped: 0.0001329 seconds, Stopping threads took: 0.0000405 seconds
2022-04-18T17:08:36.234+0800: 34.766: Total time for which application threads were stopped: 0.0000896 seconds, Stopping threads took: 0.0000497 seconds
2022-04-18T17:08:37.235+0800: 35.767: Total time for which application threads were stopped: 0.0001068 seconds, Stopping threads took: 0.0000342 seconds
2022-04-18T17:08:46.224+0800: 44.756: Total time for which application threads were stopped: 0.0001205 seconds, Stopping threads took: 0.0000381 seconds
2022-04-18T17:08:46.224+0800: 44.756: Total time for which application threads were stopped: 0.0000514 seconds, Stopping threads took: 0.0000127 seconds
2022-04-18T17:08:46.225+0800: 44.756: Total time for which application threads were stopped: 0.0000416 seconds, Stopping threads took: 0.0000108 seconds
2022-04-18T17:08:47.225+0800: 45.757: Total time for which application threads were stopped: 0.0001045 seconds, Stopping threads took: 0.0000317 seconds
2022-04-18T17:09:06.225+0800: 64.757: Total time for which application threads were stopped: 0.0001087 seconds, Stopping threads took: 0.0000361 seconds
2022-04-18T17:09:06.225+0800: 64.757: Total time for which application threads were stopped: 0.0000393 seconds, Stopping threads took: 0.0000120 seconds
2022-04-18T17:09:06.225+0800: 64.757: Total time for which application threads were stopped: 0.0000315 seconds, Stopping threads took: 0.0000071 seconds
2022-04-18T17:09:06.225+0800: 64.757: Total time for which application threads were stopped: 0.0000283 seconds, Stopping threads took: 0.0000061 seconds
2022-04-18T17:09:06.225+0800: 64.757: Total time for which application threads were stopped: 0.0000294 seconds, Stopping threads took: 0.0000066 seconds
2022-04-18T17:09:06.225+0800: 64.757: Total time for which application threads were stopped: 0.0000295 seconds, Stopping threads took: 0.0000068 seconds
2022-04-18T17:09:07.226+0800: 65.758: Total time for which application threads were stopped: 0.0001031 seconds, Stopping threads took: 0.0000311 seconds
2022-04-18T17:09:26.224+0800: 84.755: Total time for which application threads were stopped: 0.0001332 seconds, Stopping threads took: 0.0000483 seconds
2022-04-18T17:09:26.224+0800: 84.756: Total time for which application threads were stopped: 0.0000384 seconds, Stopping threads took: 0.0000087 seconds
2022-04-18T17:09:26.224+0800: 84.756: Total time for which application threads were stopped: 0.0000985 seconds, Stopping threads took: 0.0000368 seconds
2022-04-18T17:09:26.819+0800: 85.350: Total time for which application threads were stopped: 0.0001435 seconds, Stopping threads took: 0.0000357 seconds
2022-04-18T17:09:36.221+0800: 94.753: Total time for which application threads were stopped: 0.0001187 seconds, Stopping threads took: 0.0000544 seconds
2022-04-18T17:09:36.221+0800: 94.753: Total time for which application threads were stopped: 0.0000416 seconds, Stopping threads took: 0.0000102 seconds
2022-04-18T17:09:36.221+0800: 94.753: Total time for which application threads were stopped: 0.0000403 seconds, Stopping threads took: 0.0000085 seconds
2022-04-18T17:09:37.232+0800: 95.764: Total time for which application threads were stopped: 0.0001107 seconds, Stopping threads took: 0.0000369 seconds
2022-04-18T17:09:46.224+0800: 104.756: Total time for which application threads were stopped: 0.0001512 seconds, Stopping threads took: 0.0000824 seconds
2022-04-18T17:09:46.224+0800: 104.756: Total time for which application threads were stopped: 0.0000438 seconds, Stopping threads took: 0.0000105 seconds
2022-04-18T17:09:46.224+0800: 104.756: Total time for which application threads were stopped: 0.0000325 seconds, Stopping threads took: 0.0000071 seconds
2022-04-18T17:09:50.224+0800: 108.756: Total time for which application threads were stopped: 0.0001254 seconds, Stopping threads took: 0.0000511 seconds
2022-04-18T17:10:06.221+0800: 124.753: Total time for which application threads were stopped: 0.0001400 seconds, Stopping threads took: 0.0000445 seconds
2022-04-18T17:10:06.221+0800: 124.753: Total time for which application threads were stopped: 0.0000398 seconds, Stopping threads took: 0.0000105 seconds
2022-04-18T17:10:06.221+0800: 124.753: Total time for which application threads were stopped: 0.0000339 seconds, Stopping threads took: 0.0000078 seconds
2022-04-18T17:10:06.223+0800: 124.755: Total time for which application threads were stopped: 0.0001479 seconds, Stopping threads took: 0.0000570 seconds
2022-04-18T17:10:06.224+0800: 124.756: Total time for which application threads were stopped: 0.0002988 seconds, Stopping threads took: 0.0000164 seconds
2022-04-18T17:10:07.224+0800: 125.756: Total time for which application threads were stopped: 0.0001311 seconds, Stopping threads took: 0.0000561 seconds
2022-04-18T17:10:26.223+0800: 144.755: Total time for which application threads were stopped: 0.0001368 seconds, Stopping threads took: 0.0000452 seconds
2022-04-18T17:10:26.224+0800: 144.755: Total time for which application threads were stopped: 0.0000417 seconds, Stopping threads took: 0.0000113 seconds
2022-04-18T17:10:26.224+0800: 144.756: Total time for which application threads were stopped: 0.0000623 seconds, Stopping threads took: 0.0000339 seconds
2022-04-18T17:10:36.221+0800: 154.753: Total time for which application threads were stopped: 0.0001341 seconds, Stopping threads took: 0.0000569 seconds
2022-04-18T17:10:36.221+0800: 154.753: Total time for which application threads were stopped: 0.0000425 seconds, Stopping threads took: 0.0000131 seconds
2022-04-18T17:10:36.221+0800: 154.753: Total time for which application threads were stopped: 0.0000427 seconds, Stopping threads took: 0.0000126 seconds
2022-04-18T17:10:37.221+0800: 155.753: Total time for which application threads were stopped: 0.0001102 seconds, Stopping threads took: 0.0000324 seconds
2022-04-18T17:10:42.222+0800: 160.754: Total time for which application threads were stopped: 0.0001012 seconds, Stopping threads took: 0.0000307 seconds
2022-04-18T17:10:46.223+0800: 164.755: Total time for which application threads were stopped: 0.0001131 seconds, Stopping threads took: 0.0000313 seconds
2022-04-18T17:10:46.224+0800: 164.755: Total time for which application threads were stopped: 0.0000489 seconds, Stopping threads took: 0.0000181 seconds
2022-04-18T17:10:46.224+0800: 164.756: Total time for which application threads were stopped: 0.0000585 seconds, Stopping threads took: 0.0000277 seconds
2022-04-18T17:11:06.220+0800: 184.752: Total time for which application threads were stopped: 0.0001301 seconds, Stopping threads took: 0.0000591 seconds
2022-04-18T17:11:06.220+0800: 184.752: Total time for which application threads were stopped: 0.0000279 seconds, Stopping threads took: 0.0000065 seconds
2022-04-18T17:11:06.220+0800: 184.752: Total time for which application threads were stopped: 0.0000266 seconds, Stopping threads took: 0.0000059 seconds
2022-04-18T17:11:06.223+0800: 184.755: Total time for which application threads were stopped: 0.0001466 seconds, Stopping threads took: 0.0000159 seconds
2022-04-18T17:11:06.223+0800: 184.755: Total time for which application threads were stopped: 0.0000399 seconds, Stopping threads took: 0.0000092 seconds
2022-04-18T17:11:06.223+0800: 184.755: Total time for which application threads were stopped: 0.0000607 seconds, Stopping threads took: 0.0000284 seconds
2022-04-18T17:11:26.223+0800: 204.755: Total time for which application threads were stopped: 0.0001480 seconds, Stopping threads took: 0.0000524 seconds
2022-04-18T17:11:26.224+0800: 204.755: Total time for which application threads were stopped: 0.0000409 seconds, Stopping threads took: 0.0000121 seconds
2022-04-18T17:11:26.224+0800: 204.756: Total time for which application threads were stopped: 0.0000516 seconds, Stopping threads took: 0.0000199 seconds
2022-04-18T17:11:36.220+0800: 214.752: Total time for which application threads were stopped: 0.0001545 seconds, Stopping threads took: 0.0000734 seconds
2022-04-18T17:11:36.220+0800: 214.752: Total time for which application threads were stopped: 0.0000465 seconds, Stopping threads took: 0.0000086 seconds
2022-04-18T17:11:36.221+0800: 214.752: Total time for which application threads were stopped: 0.0000332 seconds, Stopping threads took: 0.0000070 seconds
2022-04-18T17:11:37.221+0800: 215.753: Total time for which application threads were stopped: 0.0001186 seconds, Stopping threads took: 0.0000483 seconds
2022-04-18T17:11:46.226+0800: 224.757: Total time for which application threads were stopped: 0.0002074 seconds, Stopping threads took: 0.0001165 seconds
2022-04-18T17:11:46.226+0800: 224.758: Total time for which application threads were stopped: 0.0000656 seconds, Stopping threads took: 0.0000247 seconds
2022-04-18T17:11:46.226+0800: 224.758: Total time for which application threads were stopped: 0.0000469 seconds, Stopping threads took: 0.0000110 seconds
2022-04-18T17:12:06.220+0800: 244.752: Total time for which application threads were stopped: 0.0001333 seconds, Stopping threads took: 0.0000543 seconds
2022-04-18T17:12:06.220+0800: 244.752: Total time for which application threads were stopped: 0.0000540 seconds, Stopping threads took: 0.0000215 seconds
2022-04-18T17:12:06.221+0800: 244.753: Total time for which application threads were stopped: 0.0000406 seconds, Stopping threads took: 0.0000129 seconds
2022-04-18T17:12:06.223+0800: 244.755: Total time for which application threads were stopped: 0.0001041 seconds, Stopping threads took: 0.0000518 seconds
2022-04-18T17:12:06.223+0800: 244.755: Total time for which application threads were stopped: 0.0000579 seconds, Stopping threads took: 0.0000260 seconds
2022-04-18T17:12:06.223+0800: 244.755: Total time for which application threads were stopped: 0.0000426 seconds, Stopping threads took: 0.0000060 seconds
2022-04-18T17:12:07.223+0800: 245.755: Total time for which application threads were stopped: 0.0001306 seconds, Stopping threads took: 0.0000315 seconds
2022-04-18T17:12:26.224+0800: 264.755: Total time for which application threads were stopped: 0.0001577 seconds, Stopping threads took: 0.0000735 seconds
2022-04-18T17:12:26.224+0800: 264.756: Total time for which application threads were stopped: 0.0000620 seconds, Stopping threads took: 0.0000280 seconds