Java CMS垃圾收集器日志输出

发布于 2024-12-27 10:48:24 字数 1522 浏览 2 评论 0原文

我正在使用 Java CMS 垃圾收集器并尝试理解日志行，例如：

22609.787: [GC 22609.788: [ParNew: 1116101K->79200K(1310720K), 0.2369136 secs]     1551730K->516431K(6029312K), 0.2379422 secs] [Times: user=1.68 sys=0.02, real=0.24 secs] 
22610.741: [Full GC 22610.741: [CMS: 437230K->278442K(4718592K), 14.8596841 secs]   573355K->278442K(6029312K), [CMS Perm : 241468K->236967K(241856K)], 14.8694544 secs]   [Times: user=14.80 sys=0.13, real=14.87 secs] 
22635.415: [GC 22635.416: [ParNew: 1048576K->43613K(1310720K), 0.0904065 secs] 1327018K->322055K(6029312K), 0.0914701 secs] [Times: user=0.45 sys=0.00, real=0.09 secs]

基于阅读 http:// blogs.oracle.com/poonam/entry/understanding_cms_gc_logs CMS 将在各种情况下执行完整的垃圾收集（例如，如果“在清理尝试中进行升级”）失败”），但根据该博客，它会记录完整 GC 的原因。

相反，我看到的是临时完整 GC。它肯定是 CMS，因为还有其他 CMS 日志条目。

是否有原因会执行完整 GC 但不记录原因？

编辑：抱歉，多个java安装（我继承了这个设置）。它实际上使用 jdk1.6.0_27

编辑不幸的是，JVM 参数包含在配置文件中（这是一个在 Tomcat 上运行的商业应用程序），但我很确定它们是：

min.heapsize=6144m
max.heapsize=6144m
-Xss=512k
-XX:MaxPermSize=512m
-XX:NewSize=1536m 
-XX:MaxNewSize=1536m 
-XX:SurvivorRatio=4 
-XX:+UseConcMarkSweepGC 
-XX:+UseParNewGC 
-XX:+UseTLAB 
-XX:+UseCompressedOops 
-XX:+PrintVMOptions 
-XX:+PrintGCDetails 
-XX:+PrintGCTimeStamps 
-XX:+PrintGCTaskTimeStamps
-XX:+PrintCommandLineFlags 
-XX:+PrintGCApplicationStoppedTime 
-XX:StackShadowPages=20 
-XX:+DisableExplicitGC

原文

I am using the Java CMS garbage collector and trying to understand log lines like:

22609.787: [GC 22609.788: [ParNew: 1116101K->79200K(1310720K), 0.2369136 secs]     1551730K->516431K(6029312K), 0.2379422 secs] [Times: user=1.68 sys=0.02, real=0.24 secs] 
22610.741: [Full GC 22610.741: [CMS: 437230K->278442K(4718592K), 14.8596841 secs]   573355K->278442K(6029312K), [CMS Perm : 241468K->236967K(241856K)], 14.8694544 secs]   [Times: user=14.80 sys=0.13, real=14.87 secs] 
22635.415: [GC 22635.416: [ParNew: 1048576K->43613K(1310720K), 0.0904065 secs] 1327018K->322055K(6029312K), 0.0914701 secs] [Times: user=0.45 sys=0.00, real=0.09 secs]

Based on reading http://blogs.oracle.com/poonam/entry/understanding_cms_gc_logs the CMS will do a full garbage collection in various situations (e.g. if "promotion in a scavenge attempt fails"), but according to that blog, it would log the reason for the full GC.

Instead I'm seeing adhoc full GCs. It definitely is CMS because there are other CMS log entries.

Are there reasons it would do a full GC but not log the reason why?

EDIT:
Sorry, multiple java installations (I've inherited this setup). It's actually using jdk1.6.0_27

EDIT
Unfortunately the JVM parameters are wrapped up in config files (this is a commercial app that runs on Tomcat), but I'm pretty sure they are:

min.heapsize=6144m
max.heapsize=6144m
-Xss=512k
-XX:MaxPermSize=512m
-XX:NewSize=1536m 
-XX:MaxNewSize=1536m 
-XX:SurvivorRatio=4 
-XX:+UseConcMarkSweepGC 
-XX:+UseParNewGC 
-XX:+UseTLAB 
-XX:+UseCompressedOops 
-XX:+PrintVMOptions 
-XX:+PrintGCDetails 
-XX:+PrintGCTimeStamps 
-XX:+PrintGCTaskTimeStamps
-XX:+PrintCommandLineFlags 
-XX:+PrintGCApplicationStoppedTime 
-XX:StackShadowPages=20 
-XX:+DisableExplicitGC

分享到QQ

分享到微博

如果你对这篇内容有疑问，欢迎到本站社区发帖提问参与讨论，获取更多帮助，或者扫码二维码加入 Web 技术交流群。

发布评论

需要登录才能够评论，你可以免费注册一个本站的账号。

梦与时光遇 2025-01-03 10:48:24

ConcurrentMarkSweepGC 在确定即将填满或已达到低水位线时将执行 GC。（我不相信这里的情况）

更可能的是某些代码直接调用 System.gc() 。例如，RMI 默认情况下每小时调用一次。您可以尝试使用 -XX:+DisableExplicitGC 看看是否有区别。如果确实如此，我会追踪原因并阻止它发生（有些人只是保留此选项）。

另一个可能的原因是可用直接内存不足。直接内存仅在 GC 上清理，但对堆大小影响不大，因此看起来确实需要 GC。当您用完直接内存时，它必须调用 System.gc() 来释放正在使用它的那些 ByteBuffer。我解决这个问题的方法是显式清理直接和内存映射的 ByteBuffer，这样我就不会用完。

另外，我会尝试 Java 6 update 30 甚至 Java 7 update 2，因为它可能具有更可预测的行为（即使您不能使用它，它也可以提供信息）

您可以尝试哪个可以告诉您触发了什么 GC（但是并不总是）

`jstat -gccause {pid} 10s`

The ConcurrentMarkSweepGC will do GC when it determines it about to fill up or its low water mark has been reached. (I don't believe its the case here)

What is more likely is that some code is calling System.gc() directly. E.g. RMI will call it every hour by default. You can try using -XX:+DisableExplicitGC to see if it makes a difference. If it does, I would trace down the cause and stop it from happening (some people just leave this option on).

Another possible cause is running low on free direct memory. Direct memory is only cleaned up on a GC but doesn't contribute much to the heap size so it does look like you need a GC. When you run out of direct memory it has to call System.gc() to free up those ByteBuffers which are using it. The way I get around it is by cleaning up direct and memory mapped ByteBuffers explicitly so I don't run out.

Also I would try Java 6 update 30 or even Java 7 update 2, as it may have more predictable behaviour (even if you can't use this it can be informative)

You could try which can tell you what a GC was triggered (but not always)