Java HotSpot 持续时间极长的年轻 Collection

Question

这是一个长时间运行的服务器应用程序，它会产生大量短暂的垃圾，并且在启动后几乎没有任何东西。大多数时候年轻一代收集速度很快，即使是 10 GB 也很快，因为它几乎都是垃圾，但我们偶尔会看到残酷的异常值。作为一个潜在的暗示，我们在一台 CPU 资源更多但内存少 12 GB 的机器上以较低的负载运行类似配置的服务器。我们在那里没有看到这种模式。

java -Xms20g -Xmx20g -Xloggc:"./logs/gc.log" -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:NewRatio=1 -XX:+DisableExplicitGC -XX:+UseSpinning -XX:PreBlockSpin=1000 -XX:-UseCounterDecay -XX:+UseTLAB -XX:+TieredCompilation -XX:ReservedCodeCacheSize=512m

这是 GC 日志的一个片段。可以肯定地说，由于 sys 时间也很高，它实际上花费了全部时间来执行 GC 工作(而不是等待线程到达安全点)吗？

2013-12-13T14:04:50.388+0000: 56748.603: [GC [PSYoungGen: 10363808K->1248K(10421824K)] 10569323K->207003K(20907584K), 0.0035110 secs] [Times: user=0.03 sys=0.00, real=0.00 secs]

2013-12-13T14:17:32.245+0000: 57510.460: [GC [PSYoungGen: 10363808K->1600K(10435072K)] 10569563K->207563K(20920832K), 0.0038460 secs] [Times: user=0.04 sys=0.00, real=0.01 secs]

2013-12-13T14:29:08.572+0000: 58206.787: [GC [PSYoungGen: 10381824K->1408K(10430912K)] 10587787K->207875K(20916672K), 0.0045710 secs] [Times: user=0.04 sys=0.00, real=0.01 secs]

2013-12-13T14:36:25.176+0000: 58643.391: [GC [PSYoungGen: 10381632K->1600K(10442432K)] 10588099K->208371K(20928192K), 0.0040800 secs] [Times: user=0.03 sys=0.00, real=0.00 secs]

2013-12-13T14:44:04.409+0000: 59102.624: [GC [PSYoungGen: 10397120K->1600K(10438848K)] 10603891K->208715K(20924608K), 14.7387710 secs] [Times: user=0.00 sys=143.05, real=14.74 secs]

2013-12-13T14:52:50.287+0000: 59628.502: [GC [PSYoungGen: 10397120K->11488K(10446720K)] 10604235K->218819K(20932480K), 0.0127280 secs] [Times: user=0.11 sys=0.00, real=0.01 secs]

2013-12-13T14:59:34.934+0000: 60033.149: [GC [PSYoungGen: 10418208K->1536K(10445760K)] 10625539K->218931K(20931520K), 211.1968100 secs] [Times: user=0.00 sys=2067.08, real=211.16 secs]

2013-12-13T15:12:04.478+0000: 60782.693: [GC [PSYoungGen: 10408256K->15136K(10448064K)] 10625651K->232723K(20933824K), 0.0147670 secs] [Times: user=0.00 sys=0.12, real=0.01 secs]

2013-12-13T15:23:02.123+0000: 61440.338: [GC [PSYoungGen: 10426912K->12672K(10448768K)] 10644499K->232635K(20934528K), 0.0141040 secs] [Times: user=0.00 sys=0.12, real=0.02 secs]

2013-12-13T15:31:09.119+0000: 61927.334: [GC [PSYoungGen: 10424448K->5280K(10452160K)] 10644411K->232907K(20937920K), 0.8134440 secs] [Times: user=1.22 sys=6.30, real=0.82 secs]

2013-12-13T15:39:25.083+0000: 62423.298: [GC [PSYoungGen: 10421024K->6208K(10449344K)] 10648651K->235547K(20935104K), 0.0087890 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]

2013-12-13T15:47:52.781+0000: 62930.996: [GC [PSYoungGen: 10421952K->7200K(10456960K)] 10651291K->239123K(20942720K), 0.0094460 secs] [Times: user=0.08 sys=0.00, real=0.01 secs]

2013-12-13T15:58:18.594+0000: 63556.809: [GC [PSYoungGen: 10433248K->6752K(10454848K)] 10665171K->242331K(20940608K), 0.0091570 secs] [Times: user=0.08 sys=0.00, real=0.01 secs]

上面服务器的规范是双 4 核 X5570 和 48 GB 内存。 HTOP 显示已使用 15 GB，其余部分与应用程序一起缓存，随时使用 10 GB 多一点(tenured 很小)。这让我认为这不是分页问题

我提到的另一台服务器是双 8 核 E5-2690，内存为 32 GB。两者都在 fedora 上运行 jre 1.7.0_25，尽管上面的服务器版本很旧

Answer 1

如此高的 sys 时间是不寻常的。它会不会干扰您系统上的某些其他应用程序/Activity ？

我认为您还应该收集其他系统统计信息 - vmstat、netstat、iostat、mpstat，以排除任何干扰或您的 GC 时间与您系统上的 Activity 。将这些与 YounGen 阶段相关联，以查看在那些长时间的 YounGen 暂停期间是否有任何尖峰。