了解 Web 应用程序中的 GC 日志和延迟

Uderstanding GC logs and delays in the web application

这是 webapp (JBoss 7.1) 的 GC 日志。如何解读这些信息? Webapp有时会有明显的延迟,我试图找出原因。

362.261: [GC [PSYoungGen: 12772K->677K(13056K)] 47780K->35813K(57600K), 0.0214030 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
375.011: [GC [PSYoungGen: 12965K->537K(13056K)] 48101K->36056K(57600K), 0.0410890 secs] [Times: user=0.01 sys=0.00, real=0.04 secs]
377.211: [GC [PSYoungGen: 12823K->764K(12800K)] 48342K->36391K(57344K), 0.0774440 secs] [Times: user=0.01 sys=0.00, real=0.08 secs]
400.197: [GC [PSYoungGen: 12796K->777K(13056K)] 48423K->36464K(57600K), 0.0204340 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
...
4222.821: [Full GC [PSYoungGen: 4096K->0K(8704K)] [ParOldGen: 55161K->40145K(55552K)] 59257K->40145K(64256K) [PSPermGen: 52107K->52107K(87552K)], 1.0148930 secs] [Times: user=0.79 sys=0.01, real=1.02 secs]

[Times: user=0.79 sys=0.01, real=1.02 secs] - 是 Stop-the-World 暂停的总结。对于 1.02 秒的挂钟时间,所有应用程序线程都被挂起(因此所有正在处理的 HTTP 请求都被延迟)。

"Full GC" 表示 major GC 年轻的和老的 space 都被收集了。 Just "GC" 是次要 GC,只收集年轻 space 中的垃圾(因此 StW 停顿更短)。

您可以在 HotSpot JVM here. If you curious about what is happening during StW pause take a look at this 文章中找到有关 GC 算法的更多信息。