2回复
4年前
G1 Ref Proc耗时增加,Eden区变小导致ygc增多
待检查的参数
java
-server
-Dfile.encoding=UTF-8
-Dsun.jnu.encoding=UTF-8
-Djava.io.tmpdir=/tmp
-Djava.net.preferIPv6Addresses=false
-Xmx12g
-Xms12g
-XX:G1HeapRegionSize=4M
-XX:ParallelGCThreads=10
-XX:MetaspaceSize=256m
-XX:MaxMetaspaceSize=256m
-XX:+HeapDumpOnOutOfMemoryError
-XX:ReservedCodeCacheSize=128m
-XX:InitialCodeCacheSize=128m
-XX:+UseG1GC
-XX:MaxGCPauseMillis=30
-XX:+PrintGCDetails
-XX:+PrintHeapAtGC
-XX:+PrintTenuringDistribution
-XX:+PrintGCTimeStamps
-XX:+PrintGCDateStamps
-XX:InitiatingHeapOccupancyPercent=50
-XX:MaxTenuringThreshold=7
-XX:+PrintAdaptiveSizePolicy
-XX:+PrintReferenceGC
最近发现线上有服务器偶尔ygc次数突增,看了下gc日志,发现由于eden区满了导致,而eden区非常小,然后在看前一次ygc,发现Ref Proc耗时增加,gc之后eden区就变小了,下面是gc日志,求大佬帮忙分析一下原因
2019-11-21T17:58:15.039+0800: 9652.917: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 425721856 bytes, new threshold 7 (max 7)
- age 1: 26659168 bytes, 26659168 total
- age 2: 83200 bytes, 26742368 total
- age 3: 23608 bytes, 26765976 total
- age 4: 62368 bytes, 26828344 total
- age 5: 13024 bytes, 26841368 total
- age 6: 21808 bytes, 26863176 total
- age 7: 108544 bytes, 26971720 total
9652.917: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 24440, predicted base time: 8.60 ms, remaining time: 21.40 ms, target pause time: 30.00 ms]
9652.917: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 1612 regions, survivors: 10 regions, predicted young region time: 21.84 ms]
9652.917: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 1612 regions, survivors: 10 regions, old: 0 regions, predicted pause time: 30.44 ms, target pause time: 30.00 ms]
9652.931: [SoftReference, 0 refs, 0.4740073 secs]9653.405: [WeakReference, 98 refs, 0.0000467 secs]9653.405: [FinalReference, 48 refs, 0.0000506 secs]9653.405: [PhantomReference, 0 refs, 7 refs, 0.0000100 secs]9653.405: [JNI Weak Reference, 0.0002777 secs], 0.4933979 secs]
[Parallel Time: 13.2 ms, GC Workers: 10]
[GC Worker Start (ms): Min: 9652917.4, Avg: 9652917.5, Max: 9652917.6, Diff: 0.2]
[Ext Root Scanning (ms): Min: 1.7, Avg: 1.9, Max: 2.5, Diff: 0.8, Sum: 19.4]
[Update RS (ms): Min: 2.5, Avg: 2.9, Max: 3.1, Diff: 0.6, Sum: 29.2]
[Processed Buffers: Min: 16, Avg: 40.1, Max: 62, Diff: 46, Sum: 401]
[Scan RS (ms): Min: 0.4, Avg: 0.5, Max: 0.6, Diff: 0.2, Sum: 5.0]
[Code Root Scanning (ms): Min: 0.1, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.8]
[Object Copy (ms): Min: 7.1, Avg: 7.3, Max: 7.3, Diff: 0.2, Sum: 72.6]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 1.1]
[GC Worker Total (ms): Min: 12.7, Avg: 12.8, Max: 13.0, Diff: 0.3, Sum: 128.1]
[GC Worker End (ms): Min: 9652930.2, Avg: 9652930.3, Max: 9652930.4, Diff: 0.2]
[Code Root Fixup: 0.3 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.9 ms]
[Other: 479.0 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 474.8 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.4 ms]
[Humongous Reclaim: 0.1 ms]
[Free CSet: 2.4 ms]
[Eden: 6448.0M(6448.0M)->0.0B(576.0M) Survivors: 40.0M->36.0M Heap: 6700.9M(12.0G)->226.0M(12.0G)]
Heap after GC invocations=259 (full 0):
garbage-first heap total 12582912K, used 231394K [0x00000004c0000000, 0x00000004c0406000, 0x00000007c0000000)
region size 4096K, 9 young (36864K), 9 survivors (36864K)
Metaspace used 117417K, capacity 120762K, committed 121088K, reserved 1157120K
class space used 12546K, capacity 13190K, committed 13312K, reserved 1048576K
}
[Times: user=0.14 sys=0.00, real=0.50 secs]
{Heap before GC invocations=259 (full 0):
garbage-first heap total 12582912K, used 821218K [0x00000004c0000000, 0x00000004c0406000, 0x00000007c0000000)
region size 4096K, 153 young (626688K), 9 survivors (36864K)
Metaspace used 117420K, capacity 120762K, committed 121088K, reserved 1157120K
class space used 12546K, capacity 13190K, committed 13312K, reserved 1048576K
2019-11-21T17:58:17.588+0800: 9655.465: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 41943040 bytes, new threshold 7 (max 7)
- age 1: 20585760 bytes, 20585760 total
- age 2: 270688 bytes, 20856448 total
- age 3: 66696 bytes, 20923144 total
- age 4: 20184 bytes, 20943328 total
- age 5: 55384 bytes, 20998712 total
- age 6: 12080 bytes, 21010792 total
- age 7: 21760 bytes, 21032552 total
9655.465: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 4337, predicted base time: 239.24 ms, remaining time: 0.00 ms, target pause time: 30.00 ms]
9655.465: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 144 regions, survivors: 9 regions, predicted young region time: 6.65 ms]
9655.465: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 144 regions, survivors: 9 regions, old: 0 regions, predicted pause time: 245.88 ms, target pause time: 30.00 ms]
9655.475: [SoftReference, 0 refs, 0.0000451 secs]9655.475: [WeakReference, 116 refs, 0.0000292 secs]9655.475: [FinalReference, 32 refs, 0.0000190 secs]9655.475: [PhantomReference, 0 refs, 7 refs, 0.0000062 secs]9655.475: [JNI Weak Reference, 0.0002180 secs], 0.0127548 secs]
[Parallel Time: 9.3 ms, GC Workers: 10]
[GC Worker Start (ms): Min: 9655465.4, Avg: 9655465.5, Max: 9655465.6, Diff: 0.2]
[Ext Root Scanning (ms): Min: 1.7, Avg: 1.9, Max: 2.4, Diff: 0.7, Sum: 18.9]
[Update RS (ms): Min: 0.5, Avg: 1.0, Max: 1.3, Diff: 0.8, Sum: 9.7]
[Processed Buffers: Min: 1, Avg: 30.9, Max: 58, Diff: 57, Sum: 309]
[Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.4]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
[Object Copy (ms): Min: 5.9, Avg: 6.0, Max: 6.1, Diff: 0.2, Sum: 60.5]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.3]
[GC Worker Total (ms): Min: 8.9, Avg: 9.0, Max: 9.1, Diff: 0.2, Sum: 89.8]
[GC Worker End (ms): Min: 9655474.5, Avg: 9655474.5, Max: 9655474.5, Diff: 0.0]
[Code Root Fixup: 0.3 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.3 ms]
[Other: 2.8 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.7 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.3 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.4 ms]
[Eden: 576.0M(576.0M)->0.0B(564.0M) Survivors: 36.0M->48.0M Heap: 802.0M(12.0G)->238.8M(12.0G)]
Heap after GC invocations=260 (full 0):
garbage-first heap total 12582912K, used 244497K [0x00000004c0000000, 0x00000004c0406000, 0x00000007c0000000)
region size 4096K, 12 young (49152K), 12 survivors (49152K)
Metaspace used 117420K, capacity 120762K, committed 121088K, reserved 1157120K
class space used 12546K, capacity 13190K, committed 13312K, reserved 1048576K
}
[Times: user=0.09 sys=0.00, real=0.02 secs]
{Heap before GC invocations=260 (full 0):
garbage-first heap total 12582912K, used 822033K [0x00000004c0000000, 0x00000004c0406000, 0x00000007c0000000)
region size 4096K, 153 young (626688K), 12 survivors (49152K)
Metaspace used 117420K, capacity 120762K, committed 121088K, reserved 1157120K
class space used 12546K, capacity 13190K, committed 13312K, reserved 1048576K
2019-11-21T17:58:20.105+0800: 9657.983: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 41943040 bytes, new threshold 7 (max 7)
- age 1: 10102336 bytes, 10102336 total
- age 2: 18236752 bytes, 28339088 total
- age 3: 258520 bytes, 28597608 total
- age 4: 62824 bytes, 28660432 total
- age 5: 20128 bytes, 28680560 total
- age 6: 55384 bytes, 28735944 total
- age 7: 12080 bytes, 28748024 total
9657.983: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 4155, predicted base time: 186.50 ms, remaining time: 0.00 ms, target pause time: 30.00 ms]
9657.983: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 141 regions, survivors: 12 regions, predicted young region time: 9.32 ms]
9657.983: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 141 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 195.82 ms, target pause time: 30.00 ms]
9657.994: [SoftReference, 0 refs, 0.0000472 secs]9657.994: [WeakReference, 122 refs, 0.0000282 secs]9657.994: [FinalReference, 23 refs, 0.0000081 secs]9657.994: [PhantomReference, 0 refs, 7 refs, 0.0000061 secs]9657.994: [JNI Weak Reference, 0.0002269 secs], 0.0131984 secs]
[Parallel Time: 9.9 ms, GC Workers: 10]
[GC Worker Start (ms): Min: 9657983.5, Avg: 9657983.6, Max: 9657983.7, Diff: 0.2]
[Ext Root Scanning (ms): Min: 1.3, Avg: 1.5, Max: 2.2, Diff: 1.0, Sum: 15.1]
[Update RS (ms): Min: 0.2, Avg: 0.8, Max: 1.3, Diff: 1.1, Sum: 8.3]
[Processed Buffers: Min: 1, Avg: 28.2, Max: 58, Diff: 57, Sum: 282]
[Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.4]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
[Object Copy (ms): Min: 6.9, Avg: 7.1, Max: 7.2, Diff: 0.3, Sum: 71.5]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.6]
[GC Worker Total (ms): Min: 9.5, Avg: 9.6, Max: 9.7, Diff: 0.2, Sum: 96.0]
[GC Worker End (ms): Min: 9657993.1, Avg: 9657993.2, Max: 9657993.3, Diff: 0.1]
[Code Root Fixup: 0.1 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.3 ms]
[Other: 2.9 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.6 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.3 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.3 ms]
[Eden: 564.0M(564.0M)->0.0B(576.0M) Survivors: 48.0M->36.0M Heap: 802.8M(12.0G)->228.0M(12.0G)]
Heap after GC invocations=261 (full 0):
garbage-first heap total 12582912K, used 233503K [0x00000004c0000000, 0x00000004c0406000, 0x00000007c0000000)
region size 4096K, 9 young (36864K), 9 survivors (36864K)
Metaspace used 117420K, capacity 120762K, committed 121088K, reserved 1157120K
class space used 12546K, capacity 13190K, committed 13312K, reserved 1048576K
}
[Times: user=0.10 sys=0.01, real=0.01 secs]
{Heap before GC invocations=261 (full 0):
garbage-first heap total 12582912K, used 828515K [0x00000004c0000000, 0x00000004c0406000, 0x00000007c0000000)
region size 4096K, 153 young (626688K), 9 survivors (36864K)
Metaspace used 117420K, capacity 120762K, committed 121088K, reserved 1157120K
class space used 12546K, capacity 13190K, committed 13312K, reserved 1048576K
6272 阅读