2013-01-15 43 views
15

我使用为什么G1 Full GC会被不必要地触发?

java version "1.7.0_09" 
Java(TM) SE Runtime Environment (build 1.7.0_09-b05) 
Java HotSpot(TM) 64-Bit Server VM (build 23.5-b02, mixed mode) 

与G1垃圾收集。 JVM argumens是

-server -Xss4096k -XX:MaxPermSize=512m -XX:PermSize=512m -Xms30G 
-Xmx30G -Xnoclassgc -XX:+UseNUMA -XX:+UseFastAccessorMethods 
-XX:ReservedCodeCacheSize=48m -XX:+UseStringCache 
-XX:+UseGCOverheadLimit -Duser.timezone=EET 
-Xmaxf1 -XX:+UseCompressedOops -XX:+DisableExplicitGC 
-XX:+AggressiveOpts -XX:CMSInitiatingOccupancyFraction=70 
-XX:+ParallelRefProcEnabled -XX:+UseAdaptiveSizePolicy 
-XX:MaxGCPauseMillis=500 -XX:+UseG1GC 
-XX:InitiatingHeapOccupancyPercent=0 
-XX:GCPauseIntervalMillis=10000 -XX:+PrintGCDetails 
-XX:+PrintHeapAtGC -XX:+PrintGCDateStamps -Xloggc:gc.log 

不过,我遇到以下全部GC的扫描没有任何明显的原因,如何摆脱他们?

GC日志从前面的事件一些尾巴:

{Heap before GC invocations=206 (full 8): 
garbage-first heap total 31457280K, used 18323299K [0x00007fc6eb800000, 0x00007fce6b800000, 0x00007fce6b800000) 
    region size 8192K, 768 young (6291456K), 31 survivors (253952K) 
compacting perm gen total 524288K, used 145771K [0x00007fce6b800000, 0x00007fce8b800000, 0x00007fce8b800000) 
    the space 524288K, 27% used [0x00007fce6b800000, 0x00007fce7465af18, 0x00007fce7465b000, 0x00007fce8b800000) 
No shared spaces configured. 
2013-01-16T11:45:31.290+0200: 20430.451: [GC pause (young), 0.54738500 secs] 
    [Parallel Time: 510.7 ms] 
     [GC Worker Start (ms): 20430451.7 20430451.8 20430451.8 20430451.8 
     Avg: 20430451.8, Min: 20430451.7, Max: 20430451.8, Diff: 0.1] 
     [Ext Root Scanning (ms): 22.3 68.3 21.8 20.8 
     Avg: 33.3, Min: 20.8, Max: 68.3, Diff: 47.5] 
     [Update RS (ms): 21.6 0.0 23.6 23.7 
     Avg: 17.3, Min: 0.0, Max: 23.7, Diff: 23.7] 
     [Processed Buffers : 77 0 18 55 
      Sum: 150, Avg: 37, Min: 0, Max: 77, Diff: 77] 
     [Scan RS (ms): 19.6 0.1 19.3 19.6 
     Avg: 14.7, Min: 0.1, Max: 19.6, Diff: 19.5] 
     [Object Copy (ms): 439.1 434.2 437.8 438.4 
     Avg: 437.4, Min: 434.2, Max: 439.1, Diff: 4.9] 
     [Termination (ms): 0.0 0.0 0.0 0.0 
     Avg: 0.0, Min: 0.0, Max: 0.0, Diff: 0.0] 
     [Termination Attempts : 1 1 1 1 
      Sum: 4, Avg: 1, Min: 1, Max: 1, Diff: 0] 
     [GC Worker End (ms): 20430954.5 20430954.6 20430954.5 20430954.4 
     Avg: 20430954.5, Min: 20430954.4, Max: 20430954.6, Diff: 0.1] 
     [GC Worker (ms): 502.7 502.8 502.7 502.6 
     Avg: 502.7, Min: 502.6, Max: 502.8, Diff: 0.2] 
     [GC Worker Other (ms): 8.0 8.0 8.0 8.1 
     Avg: 8.0, Min: 8.0, Max: 8.1, Diff: 0.1] 
    [Clear CT: 2.6 ms] 
    [Other: 34.1 ms] 
     [Choose CSet: 0.1 ms] 
     [Ref Proc: 27.4 ms] 
     [Ref Enq: 0.2 ms] 
     [Free CSet: 5.4 ms] 
    [Eden: 5896M(5896M)->0B(5688M) Survivors: 248M->456M Heap: 17893M(30720M)->12208M(30720M)] 
[Times: user=2.12 sys=0.02, real=0.55 secs] 
Heap after GC invocations=207 (full 8): 
garbage-first heap total 31457280K, used 12501684K [0x00007fc6eb800000, 0x00007fce6b800000, 0x00007fce6b800000) 
    region size 8192K, 57 young (466944K), 57 survivors (466944K) 
compacting perm gen total 524288K, used 145771K [0x00007fce6b800000, 0x00007fce8b800000, 0x00007fce8b800000) 
    the space 524288K, 27% used [0x00007fce6b800000, 0x00007fce7465af18, 0x00007fce7465b000, 0x00007fce8b800000) 
No shared spaces configured. 
} 
{Heap before GC invocations=207 (full 8): 
garbage-first heap total 31457280K, used 19058524K [0x00007fc6eb800000, 0x00007fce6b800000, 0x00007fce6b800000) 
    region size 8192K, 727 young (5955584K), 57 survivors (466944K) 
compacting perm gen total 524288K, used 145775K [0x00007fce6b800000, 0x00007fce8b800000, 0x00007fce8b800000) 
    the space 524288K, 27% used [0x00007fce6b800000, 0x00007fce7465bdd8, 0x00007fce7465be00, 0x00007fce8b800000) 
No shared spaces configured. 
2013-01-16T11:46:26.619+0200: 20485.781: [GC pause (mixed), 1.42356500 secs] 
    [Parallel Time: 1385.9 ms] 
     [GC Worker Start (ms): 20485786.6 20485786.6 20485786.6 20485786.7 
     Avg: 20485786.6, Min: 20485786.6, Max: 20485786.7, Diff: 0.1] 
     [Ext Root Scanning (ms): 22.1 70.0 22.2 21.3 
     Avg: 33.9, Min: 21.3, Max: 70.0, Diff: 48.7] 
     [Update RS (ms): 9.9 0.0 10.9 11.2 
     Avg: 8.0, Min: 0.0, Max: 11.2, Diff: 11.2] 
     [Processed Buffers : 13 0 25 17 
      Sum: 55, Avg: 13, Min: 0, Max: 25, Diff: 25] 
     [Scan RS (ms): 324.6 276.4 324.6 324.6 
     Avg: 312.5, Min: 276.4, Max: 324.6, Diff: 48.2] 
     [Object Copy (ms): 1021.1 1031.2 1019.8 1020.5 
     Avg: 1023.1, Min: 1019.8, Max: 1031.2, Diff: 11.4] 
     [Termination (ms): 0.0 0.0 0.0 0.0 
     Avg: 0.0, Min: 0.0, Max: 0.0, Diff: 0.0] 
     [Termination Attempts : 6 5 5 1 
      Sum: 17, Avg: 4, Min: 1, Max: 6, Diff: 5] 
     [GC Worker End (ms): 20487164.3 20487164.3 20487164.3 20487164.3 
     Avg: 20487164.3, Min: 20487164.3, Max: 20487164.3, Diff: 0.0] 
     [GC Worker (ms): 1377.7 1377.6 1377.6 1377.6 
     Avg: 1377.7, Min: 1377.6, Max: 1377.7, Diff: 0.1] 
     [GC Worker Other (ms): 8.2 8.3 8.3 8.3 
     Avg: 8.3, Min: 8.2, Max: 8.3, Diff: 0.1] 
    [Clear CT: 4.4 ms] 
    [Other: 33.3 ms] 
     [Choose CSet: 5.5 ms] 
     [Ref Proc: 5.0 ms] 
     [Ref Enq: 0.2 ms] 
     [Free CSet: 9.1 ms] 
    [Eden: 5360M(5688M)->0B(5784M) Survivors: 456M->360M Heap: 18616M(30720M)->11359M(30720M)] 
[Times: user=5.56 sys=0.01, real=1.42 secs] 
Heap after GC invocations=208 (full 8): 
garbage-first heap total 31457280K, used 11632594K [0x00007fc6eb800000, 0x00007fce6b800000, 0x00007fce6b800000) 
    region size 8192K, 45 young (368640K), 45 survivors (368640K) 
compacting perm gen total 524288K, used 145775K [0x00007fce6b800000, 0x00007fce8b800000, 0x00007fce8b800000) 
    the space 524288K, 27% used [0x00007fce6b800000, 0x00007fce7465bdd8, 0x00007fce7465be00, 0x00007fce8b800000) 
No shared spaces configured. 
} 
{Heap before GC invocations=208 (full 8): 
garbage-first heap total 31457280K, used 11632594K [0x00007fc6eb800000, 0x00007fce6b800000, 0x00007fce6b800000) 
    region size 8192K, 45 young (368640K), 45 survivors (368640K) 
compacting perm gen total 524288K, used 145775K [0x00007fce6b800000, 0x00007fce8b800000, 0x00007fce8b800000) 
    the space 524288K, 27% used [0x00007fce6b800000, 0x00007fce7465bdd8, 0x00007fce7465be00, 0x00007fce8b800000) 
No shared spaces configured. 
2013-01-16T11:46:28.060+0200: 20487.222: [Full GC 11359M->8807M(30720M), 32.4879420 secs] 
[Times: user=45.41 sys=0.21, real=32.48 secs] 
Heap after GC invocations=209 (full 9): 
garbage-first heap total 31457280K, used 9019206K [0x00007fc6eb800000, 0x00007fce6b800000, 0x00007fce6b800000) 
    region size 8192K, 0 young (0K), 0 survivors (0K) 
compacting perm gen total 524288K, used 145775K [0x00007fce6b800000, 0x00007fce8b800000, 0x00007fce8b800000) 
    the space 524288K, 27% used [0x00007fce6b800000, 0x00007fce7465bdd8, 0x00007fce7465be00, 0x00007fce8b800000) 
No shared spaces configured. 
} 

其他类似的:

{Heap before GC invocations=105 (full 4): 
garbage-first heap total 31457280K, used 12638024K [0x00007fcb22800000, 0x00007fd2a2800000, 0x00007fd2a2800000) 
    region size 8192K, 56 young (458752K), 56 survivors (458752K) 
compacting perm gen total 524288K, used 147352K [0x00007fd2a2800000, 0x00007fd2c2800000, 0x00007fd2c2800000) 
    the space 524288K, 28% used [0x00007fd2a2800000, 0x00007fd2ab7e61f8, 0x00007fd2ab7e6200, 0x00007fd2c2800000) 
No shared spaces configured. 
2013-01-14T10:31:31.240+0200: 14185.812: [Full GC 12341M->7092M(30720M), 25.3417840 secs] 
[Times: user=35.12 sys=0.21, real=25.33 secs] 
Heap after GC invocations=106 (full 5): 
garbage-first heap total 31457280K, used 7262578K [0x00007fcb22800000, 0x00007fd2a2800000, 0x00007fd2a2800000) 
    region size 8192K, 0 young (0K), 0 survivors (0K) 
compacting perm gen total 524288K, used 147352K [0x00007fd2a2800000, 0x00007fd2c2800000, 0x00007fd2c2800000) 
    the space 524288K, 28% used [0x00007fd2a2800000, 0x00007fd2ab7e61f8, 0x00007fd2ab7e6200, 0x00007fd2c2800000) 
No shared spaces configured. 
} 

{Heap before GC invocations=248 (full 11): 
garbage-first heap total 31457280K, used 12262418K [0x00007fcb22800000, 0x00007fd2a2800000, 0x00007fd2a2800000) 
    region size 8192K, 37 young (303104K), 37 survivors (303104K) 
compacting perm gen total 524288K, used 152608K [0x00007fd2a2800000, 0x00007fd2c2800000, 0x00007fd2c2800000) 
    the space 524288K, 29% used [0x00007fd2a2800000, 0x00007fd2abd082e8, 0x00007fd2abd08400, 0x00007fd2c2800000) 
No shared spaces configured. 
2013-01-14T13:01:39.869+0200: 23194.441: [Full GC 11975M->7331M(30720M), 28.6147390 secs] 
[Times: user=40.31 sys=0.03, real=28.62 secs] 
Heap after GC invocations=249 (full 12): 
garbage-first heap total 31457280K, used 7507920K [0x00007fcb22800000, 0x00007fd2a2800000, 0x00007fd2a2800000) 
    region size 8192K, 0 young (0K), 0 survivors (0K) 
compacting perm gen total 524288K, used 152608K [0x00007fd2a2800000, 0x00007fd2c2800000, 0x00007fd2c2800000) 
    the space 524288K, 29% used [0x00007fd2a2800000, 0x00007fd2abd082e8, 0x00007fd2abd08400, 0x00007fd2c2800000) 
No shared spaces configured. 
} 

{Heap before GC invocations=399 (full 19): 
garbage-first heap total 31457280K, used 13016093K [0x00007fcb22800000, 0x00007fd2a2800000, 0x00007fd2a2800000) 
    region size 8192K, 54 young (442368K), 54 survivors (442368K) 
compacting perm gen total 524288K, used 155475K [0x00007fd2a2800000, 0x00007fd2c2800000, 0x00007fd2c2800000) 
    the space 524288K, 29% used [0x00007fd2a2800000, 0x00007fd2abfd4c70, 0x00007fd2abfd4e00, 0x00007fd2c2800000) 
No shared spaces configured. 
2013-01-14T15:31:36.484+0200: 32191.056: [Full GC 12711M->7543M(30720M), 29.secs] 
[Times: user=41.39 sys=0.06, real=29.50 secs] 
Heap after GC invocations=400 (full 20): 
garbage-first heap total 31457280K, used 7724994K [0x00007fcb22800000, 0x00007fd2a2800000, 0x00007fd2a2800000) 
    region size 8192K, 0 young (0K), 0 survivors (0K) 
compacting perm gen total 524288K, used 155475K [0x00007fd2a2800000, 0x00007fd2c2800000, 0x00007fd2c2800000) 
    the space 524288K, 29% used [0x00007fd2a2800000, 0x00007fd2abfd4c70, 0x00007fd2abfd4e00, 0x00007fd2c2800000) 
No shared spaces configured. 
} 

{Heap before GC invocations=476 (full 26): 
garbage-first heap total 31457280K, used 14622246K [0x00007fcb22800000, 0x00007fd2a2800000, 0x00007fd2a2800000) 
    region size 8192K, 27 young (221184K), 27 survivors (221184K) 
compacting perm gen total 524288K, used 156716K [0x00007fd2a2800000, 0x00007fd2c2800000, 0x00007fd2c2800000) 
    the space 524288K, 29% used [0x00007fd2a2800000, 0x00007fd2ac10b2b0, 0x00007fd2ac10b400, 0x00007fd2c2800000) 
No shared spaces configured. 
2013-01-14T18:46:41.545+0200: 43896.117: [Full GC 14279M->8107M(30720M), 31.6936770 secs] 
[Times: user=44.40 sys=0.18, real=31.69 secs] 
Heap after GC invocations=477 (full 27): 
garbage-first heap total 31457280K, used 8302054K [0x00007fcb22800000, 0x00007fd2a2800000, 0x00007fd2a2800000) 
    region size 8192K, 0 young (0K), 0 survivors (0K) 
compacting perm gen total 524288K, used 156551K [0x00007fd2a2800000, 0x00007fd2c2800000, 0x00007fd2c2800000) 
    the space 524288K, 29% used [0x00007fd2a2800000, 0x00007fd2ac0e1fa0, 0x00007fd2ac0e2000, 0x00007fd2c2800000) 
No shared spaces configured. 
} 

{Heap before GC invocations=522 (full 34): 
garbage-first heap total 31457280K, used 16096219K [0x00007fcb22800000, 0x00007fd2a2800000, 0x00007fd2a2800000) 
    region size 8192K, 30 young (245760K), 30 survivors (245760K) 
compacting perm gen total 524288K, used 156869K [0x00007fd2a2800000, 0x00007fd2c2800000, 0x00007fd2c2800000) 
    the space 524288K, 29% used [0x00007fd2a2800000, 0x00007fd2ac1315d8, 0x00007fd2ac131600, 0x00007fd2c2800000) 
No shared spaces configured. 
2013-01-14T22:31:40.711+0200: 57395.283: [Full GC 15718M->11933M(30720M), 42.0857250 secs] 
[Times: user=60.13 sys=0.07, real=42.08 secs] 
Heap after GC invocations=523 (full 35): 
garbage-first heap total 31457280K, used 12219927K [0x00007fcb22800000, 0x00007fd2a2800000, 0x00007fd2a2800000) 
    region size 8192K, 0 young (0K), 0 survivors (0K) 
compacting perm gen total 524288K, used 156869K [0x00007fd2a2800000, 0x00007fd2c2800000, 0x00007fd2c2800000) 
    the space 524288K, 29% used [0x00007fd2a2800000, 0x00007fd2ac1315d8, 0x00007fd2ac131600, 0x00007fd2c2800000) 
No shared spaces configured. 
} 

其他类似的问题报告:

http://grokbase.com/t/openjdk/hotspot-gc-use/1192sy84j5/g1c-strange-full-gc-behavior http://grokbase.com/p/openjdk/hotspot-gc-use/123ydf9c92/puzzling-why-is-a-full-gc-triggered-here http://mail.openjdk.java.net/pipermail/hotspot-gc-use/2013-February/001484.html

我一直在使用appdynamics分析器分析问题,并且我发现每次发生完全GC时,代码缓存(配置为最大值)已满。这似乎是GC中的一个错误。

另请参阅探查器图像,两个不必要的Full GC:在24/5和25/5之间的中间。更重要的是,他们杀了服务器的可用性,因为他们最后各60秒后:

Profiler log image http://eisler.vps.kotisivut.com/logs/g1gc-code-cache-full-gc-bug-illustration.png

参见关于Azul的pauseless GC讨论,他们似乎已经制定了这样的问题http://www.artima.com/lejava/articles/azul_pauseless_gc.html

+0

是整个GS日志,还是你离开/编辑过的东西? –

+0

整个GS日志超过24小时,所以是编辑版本的简单多汁部分。 – Martin

+0

那么为什么JVM *需要*做完整的GC的线索不在这里。 –

回答

5

我们记录这个bug在1.7 ._u06,并在几天前升级到1.7.0_21-b11,并且自从升级以来我们还没有看到任何完整的GC,所以它看起来像是在JVM中修复了这个bug。代码缓存内存配置文件现在在配置文件中看起来也好多了。过去,这个问题曾经是每天一次,每天更多次。

如果情况发生变化,我会回报。在此之前,我认为升级解决了这个问题。

+0

我们遇到了无法用热点jvm解决的更高负载问题。最后,我们找到了Azul的Zing jvm的更长期解决方案。我的经验是非常积极的,几乎所有的问题都没有了,我花了零时间来调整它。 考虑到我以前每天花费几个小时调整和分析g1gc,这相当重要,相当节省成本,每个工作日可以节省20天。 最重要的好处是: 1)不需要调整 2)否完整GC:s更长,以毫秒为单位的最长延迟 3)http://www.azulsystems.com/products/zing/technical-case – Martin

7

请参阅我的回复在 G1GC long pause with initial-mark

你的每一个环境都应该有一个坚实的理由在这里......不幸的是他们中的一些人没有例如-XX:+UseBiasedLocking (used for combination of tenured and young generation GCs, but G1GC is capable to handle both) -XX:+DisableExplicitGC (its unpredictable, in my experience its never restrict explicit gc calls)

请使用/调整相应下文提到的设置,以获得最佳效果,我给你基线前进,希望如此,这些设置会为你工作: Java G1 garbage collection in production

+0

谢谢。我们有一些'霰弹枪'参数的原因是因为他们是如此糟糕的记录什么去哪里,哪些影响哪些...为什么你认为'+ UseAdaptiveSizePolicy'不是一个好主意?在JDK7中默认情况下应该启用“-XX:+ DoEscapeAnalysis”? GCPauseIntervalMillis的实际值是否重要,或只是比率MaxGCPauseMillis/GCPauseIntervalMillis? – Martin

+0

此答案尚未解决问题。 – Martin

+0

@emkays当你的堆大于6GB时,建议使用G1。 – Vipin

相关问题