我正在调整G1GC,以避免发生FullGC。
按照http://www.infoq.com/articles/tuning-tips-G1-GC的提示,我看不到任何日志,例如“空间耗尽”。
Java HotSpot(TM) 64-Bit Server VM (24.76-b04) for linux-amd64 JRE (1.7.0_76-b13), built on Dec 18 2014 16:58:39 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 32934888k(13890072k free), swap 48197628k(48197628k free)
CommandLine flags:
-XX:AutoBoxCacheMax=3000000 -XX:ConcGCThreads=4 -XX:+DisableExplicitGC -XX:G1ReservePercent=25 -XX:+HeapDumpOnOutOfMemoryError -XX:InitialHeapSize=11811160064 -XX:MaxDirectMemorySize=1073741824 -XX:MaxGCPauseMillis=1000 -XX:MaxHeapSize=11811160064 -XX:-OmitStackTraceInFastThrow
-XX:ParallelGCThreads=8 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps
-XX:+PrintTenuringDistribution -XX:+UseCompressedOops -XX:+UseG1GC
出于其他原因,GC会决定执行完整收集吗?
还是疏散失败,但未启用日志?
70861.400: [GC pause (mixed)
Desired survivor size 37748736 bytes, new threshold 1 (max 15)
- age 1: 49450208 bytes, 49450208 total
- age 2: 3236616 bytes, 52686824 total
- age 3: 10086240 bytes, 62773064 total
- age 4: 188936 bytes, 62962000 total
- age 5: 816536 bytes, 63778536 total
- age 6: 1024560 bytes, 64803096 total
- age 7: 1341640 bytes, 66144736 total
- age 8: 1562648 bytes, 67707384 total
- age 9: 59200 bytes, 67766584 total
, 0.2471520 secs]
[Parallel Time: 225.0 ms, GC Workers: 8]
[GC Worker Start (ms): Min: 70861401.2, Avg: 70861401.4, Max: 70861401.7, Diff: 0.6]
[Ext Root Scanning (ms): Min: 3.8, Avg: 4.1, Max: 4.5, Diff: 0.6, Sum: 33.0]
[Update RS (ms): Min: 93.2, Avg: 93.4, Max: 93.5, Diff: 0.3, Sum: 746.9]
[Processed Buffers: Min: 92, Avg: 108.0, Max: 124, Diff: 32, Sum: 864]
[Scan RS (ms): Min: 29.7, Avg: 29.7, Max: 29.8, Diff: 0.1, Sum: 238.0]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Object Copy (ms): Min: 95.9, Avg: 96.2, Max: 97.0, Diff: 1.1, Sum: 769.6]
[Termination (ms): Min: 0.0, Avg: 0.8, Max: 1.0, Diff: 1.0, Sum: 6.4]
[GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.3, Diff: 0.2, Sum: 0.7]
[GC Worker Total (ms): Min: 224.1, Avg: 224.3, Max: 224.6, Diff: 0.6, Sum: 1794.6]
[GC Worker End (ms): Min: 70861625.7, Avg: 70861625.7, Max: 70861625.9, Diff: 0.2]
[Code Root Fixup: 0.2 ms]
[Code Root Migration: 0.1 ms]
[Clear CT: 4.8 ms]
[Other: 17.2 ms]
[Choose CSet: 0.4 ms]
[Ref Proc: 7.5 ms]
[Ref Enq: 0.1 ms]
[Free CSet: 1.0 ms]
[Eden: 488.0M(488.0M)->0.0B(2956.0M) Survivors: 72.0M->20.0M Heap: 5882.4M(11.0G)->5394.1M(11.0G)]
71319.172: [GC pause (young) (initial-mark)
Desired survivor size 195035136 bytes, new threshold 15 (max 15)
- age 1: 3965480 bytes, 3965480 total
, 0.2243330 secs]
[Parallel Time: 182.7 ms, GC Workers: 8]
[GC Worker Start (ms): Min: 71319173.4, Avg: 71319173.6, Max: 71319174.0, Diff: 0.6]
[Ext Root Scanning (ms): Min: 3.4, Avg: 4.0, Max: 4.4, Diff: 1.0, Sum: 31.8]
[Code Root Marking (ms): Min: 2.0, Avg: 2.7, Max: 6.0, Diff: 4.0, Sum: 21.4]
[Update RS (ms): Min: 105.7, Avg: 109.2, Max: 110.6, Diff: 4.9, Sum: 873.2]
[Processed Buffers: Min: 115, Avg: 127.6, Max: 142, Diff: 27, Sum: 1021]
[Scan RS (ms): Min: 11.7, Avg: 12.6, Max: 12.9, Diff: 1.1, Sum: 100.9]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
[Object Copy (ms): Min: 52.2, Avg: 52.7, Max: 52.9, Diff: 0.7, Sum: 421.2]
[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.2, Max: 0.6, Diff: 0.6, Sum: 1.9]
[GC Worker Total (ms): Min: 181.0, Avg: 181.3, Max: 181.6, Diff: 0.6, Sum: 1450.7]
[GC Worker End (ms): Min: 71319354.8, Avg: 71319355.0, Max: 71319355.3, Diff: 0.6]
[Code Root Fixup: 0.3 ms]
[Code Root Migration: 0.2 ms]
[Clear CT: 3.6 ms]
[Other: 37.6 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 29.8 ms]
[Ref Enq: 0.5 ms]
[Free CSet: 2.3 ms]
[Eden: 2332.0M(2956.0M)->0.0B(2872.0M) Survivors: 20.0M->72.0M Heap: 7725.6M(11.0G)->5448.0M(11.0G)]
[Times: user=1.51 sys=0.00, real=0.22 secs]
71319.397: [GC concurrent-root-region-scan-start]
71319.468: [GC concurrent-root-region-scan-end, 0.0707700 secs]
71319.468: [GC concurrent-mark-start]
71320.512: [GC pause (young)
Desired survivor size 192937984 bytes, new threshold 15 (max 15)
- age 1: 57002072 bytes, 57002072 total
- age 2: 3685360 bytes, 60687432 total
, 0.1300980 secs]
[Parallel Time: 122.5 ms, GC Workers: 8]
[GC Worker Start (ms): Min: 71320513.1, Avg: 71320513.3, Max: 71320513.8, Diff: 0.7]
[Ext Root Scanning (ms): Min: 3.5, Avg: 4.0, Max: 4.3, Diff: 0.8, Sum: 32.4]
[SATB Filtering (ms): Min: 0.0, Avg: 0.1, Max: 0.8, Diff: 0.8, Sum: 0.8]
[Update RS (ms): Min: 75.2, Avg: 75.7, Max: 76.0, Diff: 0.8, Sum: 605.8]
[Processed Buffers: Min: 169, Avg: 183.8, Max: 202, Diff: 33, Sum: 1470]
[Scan RS (ms): Min: 2.9, Avg: 2.9, Max: 3.0, Diff: 0.1, Sum: 23.3]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Object Copy (ms): Min: 38.7, Avg: 38.8, Max: 38.9, Diff: 0.1, Sum: 310.4]
[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.5]
[GC Worker Total (ms): Min: 121.2, Avg: 121.7, Max: 121.9, Diff: 0.7, Sum: 973.3]
[GC Worker End (ms): Min: 71320635.0, Avg: 71320635.0, Max: 71320635.0, Diff: 0.0]
[Code Root Fixup: 0.2 ms]
[Code Root Migration: 0.0 ms]
[Clear CT: 1.4 ms]
[Other: 6.0 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.7 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.5 ms]
[Eden: 260.0M(2872.0M)->0.0B(2736.0M) Survivors: 72.0M->68.0M Heap: 5828.3M(11.0G)->5562.4M(11.0G)]
[Times: user=0.98 sys=0.00, real=0.12 secs]
71320.645: [Full GC 5562M->3567M(11G), 23.7159350 secs]
[Eden: 0.0B(2736.0M)->0.0B(4804.0M) Survivors: 68.0M->0.0B Heap: 5562.4M(11.0G)->3567.2M(11.0G)], [Perm: 34637K->34637K(36864K)]
[Times: user=38.34 sys=0.02, real=23.72 secs]
71344.362: [GC concurrent-mark-abort]
71436.544: [GC pause (young)
Desired survivor size 316669952 bytes, new threshold 15 (max 15)
- age 1: 448512 bytes, 448512 total
- age 2: 55511136 bytes, 55959648 total
- age 3: 3685280 bytes, 59644928 total
, 0.2012910 secs]
[Parallel Time: 183.5 ms, GC Workers: 8]
[GC Worker Start (ms): Min: 71436545.9, Avg: 71436546.2, Max: 71436546.6, Diff: 0.7]
[Ext Root Scanning (ms): Min: 5.2, Avg: 5.4, Max: 5.9, Diff: 0.7, Sum: 43.3]
[Update RS (ms): Min: 44.0, Avg: 45.8, Max: 52.6, Diff: 8.6, Sum: 366.0]
[Processed Buffers: Min: 118, Avg: 128.2, Max: 136, Diff: 18, Sum: 1026]
[Scan RS (ms): Min: 5.2, Avg: 11.8, Max: 13.5, Diff: 8.3, Sum: 94.4]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.3]
[Object Copy (ms): Min: 118.8, Avg: 118.9, Max: 119.1, Diff: 0.3, Sum: 951.4]
[Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.5]
[GC Worker Other (ms): Min: 0.0, Avg: 0.3, Max: 0.5, Diff: 0.5, Sum: 2.3]
[GC Worker Total (ms): Min: 181.9, Avg: 182.3, Max: 182.6, Diff: 0.7, Sum: 1458.3]
[GC Worker End (ms): Min: 71436728.2, Avg: 71436728.5, Max: 71436728.7, Diff: 0.5]
[Code Root Fixup: 0.2 ms]
[Code Root Migration: 0.3 ms]
[Clear CT: 4.2 ms]
[Other: 13.1 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 6.6 ms]
[Ref Enq: 0.1 ms]
[Free CSet: 3.6 ms]
[Eden: 4804.0M(4804.0M)->0.0B(3412.0M) Survivors: 0.0B->152.0M Heap: 9208.4M(11.0G)->4554.4M(11.0G)]
[Times: user=1.50 sys=0.00, real=0.20 secs]
它在71320.645上启动了FullGC,但是看起来没有发生疏散失败,有什么想法吗?
最佳答案
在Java 7上运行G1GC可能不是一个好主意。那时,它有很多有问题的行为。其中,类卸载需要完整的GC,this has been fixed with jdk8u40
更不用说GC日志在8中提供了更多有用的信息。
但是,其他原因也是可以考虑的,例如,庞大的对象分配需要比可用的连续更多的空闲区域。 8的日志可能更有用。
编辑:实际上,该功能可能在标志后面的7u45中,请尝试-XX:+PrintGCCause