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

本文介绍了理解Web应用程序中的GC日志和延迟的处理方法，对大家解决问题具有一定的参考价值，需要的朋友们下面随着小编来一起学习吧！ 问题描述

这是webapp（JBoss 7.1）的GC日志。如何解释这些信息？ Webapp有时会出现明显的延迟，我试图找到原因。

362.261：[GC [PSYoungGen：12772K- > 677K（13056K）] 47780K-> 35813K（57600K），0.0214030秒] [时间：用户= 0.01 sys = 0.00，实际= 0.02秒] 375.011：[GC [PSYoungGen：12965K-> 537K （13056K）] 48101K-> 36056K（57600K），0.0410890秒] [时间：用户= 0.01 sys = 0.00，实际= 0.04秒] 377.211：[GC [PSYoungGen：12823K-> 764K（12800K） ] 48342K-> 36391K（57344K），0.0774440秒] [时间：用户= 0.01 sys = 0.00，实际= 0.08秒] 400.197：[GC [PSYoungGen：12796K-> 777K（13056K）] 48423K- > 36464K（57600K），0.0204340秒] [时间：用户= 0.01 sys = 0.00，实际= 0.02秒] ... 4222.821：[Full GC [PSYoungGen：4096K-> 0K （时间：用户= 0.79，系统= 0.01，真实的，实际的，实际的） = 1.02秒]

解决方案

[ Times：user = 0.79 sys = 0.01 ，真实= 1.02秒] - 是停止世界暂停的摘要。对于挂钟时间1.02秒，所有应用程序线程都被暂停（因此所有正在处理的HTTP请求都被延迟）。Full GC意思是当年轻人和旧空间被收集。只是GC是小GC，只收集年轻空间的垃圾（因此StW暂停时间更短）。

您可以在HotSpot JVM中找到有关GC算法的更多信息此处。如果您对StW暂停期间发生的事情感到好奇，请查看这篇文章。

This is a GC logs of webapp (JBoss 7.1). How to interpret this information? Webapp sometimes has noticeable delays and I try to find the reason.

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] - is a summary of Stop-the-World pause. For 1.02 secs of wallclock time all application threads were suspended (thus all HTTP request being processed were delayed).

"Full GC" means major GC when both young and old space is collected. Just "GC" is minor GC, only garbage in young space is collected (thus StW pause is shorter).

You can find more information about GC algorithm available in HotSpot JVM here. If you curious about what is happening during StW pause take a look at this article.