本文介绍了JVM GC问题的处理方法，对大家解决问题具有一定的参考价值，需要的朋友们下面随着小编来一起学习吧！
问题描述
在过去的几周里，我一直在为我的Glassfish服务器测试不同的JVM设置。堆（除其他外）的主要设置是：-Xms512m，-Xmx512m，-XX：NewRatio = 2。我尝试了不同的GC设置，但在启动服务器几天后，我仍然遇到长时间停顿的问题。我注意到以下几点：1. -XX：+ UseParallelGC -XX：+ UseParallelOldGC - 小GC每18分钟发生一次，主GC每隔18小时发生一次。我对小型GC没有任何问题，但5天后主要GC出现问题。一开始，主要的GC暂停持续了大约100-200ms，但最后一次暂停持续了70秒。
2. -XX：+ UseConcMarkSweepGC -XX：+ UseParNewGC - 与上述几乎相同。未成年人GC很好，但主要的GC（不全）停顿时间变得很长。
我注意到GC（CMS Final Remark）阶段的高级卸载问题已经停止了世界阶段。
3. -XX：+ UseConcMarkSweepGC -XX：+ UseParNewGC和-XX：MaxGCPauseMillis = 5000。我测试了这个只有一天，因为第二个主要的GC最后（不完整）已经持续了大约20秒，所以我认为还有其他的错误。
4. -XX：+ UseG1GC， - XX：MaxGCPauseMillis = 5000，-XX：+ UseStringDeduplication没有-XX：NewRatio = 2选项 - 主要的GC（未满）每12小时发生一次，我已经注意到一些问题了：
2015-05-31T18：25：25.145 + 0200：83383.897：[GC concurrent-mark-start]
2015-05-31T18： 25：35.563 + 0200：83394.312：[GC同时标记结束，10.4145795秒]
2015-05-31T18：25：35.563 + 0200：83394.312：[GC备注83394.312：[结束标记，0.0002939秒] 83394.312 ：[GC ref-proc，1.2128584 secs] 83395.525：[Unloading，14.5180500 secs]，15.7320854 secs]
[Times：user = 0.14 sys = 0.22，real = 15.73 secs]
GC备注阶段耗时15秒，这对我来说是不可接受的。你可以看到大部分时间都在卸货。
总结：所有GC运行良好一段时间，但几天后问题开始出现出现很长的停顿时间。我不知道为什么它前几天工作正常，然后突然结果非常糟糕。我注意到更高的停顿时间是由班级卸载引起的，所以我想知道是否有一些设置可以获得更好的结果。另外我想知道你推荐给我使用哪个GC？我有内置的web应用程序，运行在带有8GB RAM，i7处理器和Windows 8操作系统的PC上的glassfish服务器上。同时将有最多10个客户端连接，但它必须具有很长的正常运行时间并且不能有很长的暂停时间（最多5秒）。请告诉我，我还能做些什么来缩短暂停时间。
还有一个问题：使用G1GC而不是CMS或ParallelGC在我案件？是G1GC的小堆？
编辑：G1GC日志权利前后长时间停留GC备注阶段
2015-05-31T18：25：25.004 + 0200：83383.755：[GC暂停（G1撤退暂停）（年轻）（初始标记），0.1280453秒]
[并行时间：116.2毫秒，GC工作人员：4]
[GC工作人员开始时间（毫秒）：最小值：83383757.6，平均值：83383757.7，最大值：83383757.7，差值：0.0]扫描（毫秒）：最小值：97.8，平均值：98.3，最大值：98.5，差值：0.7，总和：393.1]
[更新RS（ms）：最小值：0.2，平均值：4.0，最大值：14.8， 14.6，总和：16.1]
[处理的缓冲区：最小值：1，平均值：6.0，最大值：16，差值：15，总和值：24]
[扫描RS（ms）：最小值： ：0.0，Max：0.1，Diff：0.1，Sum：0.1]
[代码根扫描（ms）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.0]
[对象拷贝（ms）：最小值：0.2，平均值：2.5，最大值：3.7，差值：3.5，总和值：10.2]
[终止值（ms）：最小值：0.0，平均值：8.5，最大值：差异：11.4，总和：34.2]
[GC Worker Other（ms）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.0]
[GC Worker Total [GC Worker End（ms）：Min：83383871.1，Avg：83383871.1，Max：83383871.1，Diff：0.0]
[Code Root Fixup：0.1 ms]
[Code Root Purge：0.0 ms]
[String Dedup Fixup：2.2 ms，GC Workers：4]
[Queue Fixup（ms）：Min：0.0，Avg：0.0，Max： 0.0，Diff：0.0，Sum：0.0]
[Table Fixup（ms）：Min：2.0，Avg：2.1，Max：2.1，Diff：0.1，Sum：8.3]
[Clear CT：0.1
[Ref Enq：8.8 ms]
[Ref Enq：0.1 ms]
[其他：9.5 ms]
[选择CSet：0.0 ms] （免费CSet：0.1毫秒]
[伊甸园：215.0M（215.0M） - > 0.0B（215.0M）]
[Hummonous Reclaim：0.0 ms]
[幸存者：7168.0K-> 7168.0K堆：451.5M（512.0M） - > 236.6M（512.0M）]
[时间：用户= 0.08 sys = 0.02，实际= 0.13秒]
2015-05-31T18：25：25.129 + 020 0：83383.883：[GC concurrent-root-region-scan-start]
2015-05-31T18：25：25.129 + 0200：83383.883：[GC concurrent-string-deduplication，160.0B-> 0.0B
[检查：3]
[跳过：0.0000070秒，空闲：23.1834927秒，阻止：0 / 0.0000000秒] 0（0.0％）]
[散列：3（100.0％）]
[已知：0（0.0％）]
[新：3（100.0％）160.0B] b [减重3（100.0％）160.0B（100.0％）]
[年轻：3（100.0％）160.0B（100.0％）]
[旧：0（0.0％）0.0B 0.0％）]
[总执行：2868 / 0.1946124秒，空闲：2868 / 83382.9701762秒，阻止：13 / 0.0032760秒]
[检查：304493]
[跳过：0 ％）]
[散列：163708（53.8％）]
[已知：44808（14.7％）]
[新增：259685（85.3％）2190万]
[减重：160467（61.8％）10.6M（48.3％）]
[年轻：83546（52.1％）6270.6K（57.8％ ）]
[旧]：76921（47.9％）4571.3（42.2％）]
[表]
[内存使用量：4291.8K]
[大小：131072，
[Entries：133319，Load：101.7％，Cached：6107，Added：142389，Removed：9070]
[Resize Count：7，Shrink Threshold：87381（66.7％） ，增长阈值：262144（200.0％）]
[Rehash Count：0，Rehash Threshold：120，Hash Seed：0x0]
[年龄阈值：3]
[Queue]
[已丢弃：0]
2015-05-31T18：25：25.145 + 0200：83383.897：[GC并发根区域扫描结束，0.0140467秒]
2015-05-31T18：25 ：25.145 + 0200：83383.897：[GC并发标记开始]
2015-05-31T18：25：35.563 + 0200：83394.312：[GC并发标记结束，10.4145795秒]
2015- 05-31T18：25：35.563 + 0200：83394.312：[GC备注83394.3 12：[完成标记，0.0002939秒] 83394.312：[GC ref-proc，1.2128584秒] 83395.525：[卸载14.5180500秒]，15.7320854秒]
[时间：用户= 0.14 sys = 0.22，实际= 15.73秒]
2015-05-31T18：25：51.288 + 0200：83410.045：[GC清除334M-> 326M（512M），0.2836092秒]
[时间：用户= 0.00 sys = 0.00， 0.28秒]
2015-05-31T18：25：51.570 + 0200：83410.328：[GC并发清理开始]
2015-05-31T18：25：51.570 + 0200：83410.328：[GC并发$清洁结束，0.0000669秒]
2015-05-31T18：26：03.732 + 0200：83422.482：[GC暂停（G1撤退暂停）（年轻），0.1031257秒]
[并行时间：91.6 ms，GC Worker：4]
[GC Worker Start（ms）：Min：83422481.7，Avg：83422481.7，Max：83422481.8，Diff：0.0]
[Ext Root Scanning（ms）：Min：1.3 ，Avg：1.7，Max：2.7，Diff：1.4，Sum：6.9]
[更新RS（ms）：Min：0.0，Avg：22.7，Max：89.8，Diff：89.8，Sum：90.8]
[已处理的缓冲区：最小值：0，平均值：7.3，最大值：15，差值：15，总和：29]
[Scan RS（ms）：Min：0.0，Avg：0.0，Max：0.1，Diff：0.1，Sum：0.2]
[Code Root Scanning [Max：0.0，Diff：0.0，Sum：0.0]
[Object Copy（ms）：Min：0.5，Avg：2.4，Max：3.4，Diff：2.9，Sum：9.5]
[ ms）：Min：0.0，Avg：64.7，Max：86.3，Diff：86.3，Sum：258.9]
[GC Worker Other（ms）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0 ，总和：0.1]
[GC工作人员总数（毫秒）：最小值：91.6，平均值：91.6，最大值：91.6，差值：0.0，总和：366.3] ：83422573.3，Avg：83422573.3，Max：83422573.3，Diff：0.0]
[Code Root Fixup：0.1 ms]
[Code Root Purge：0.0 ms]
[String Dedup Fixup：2.1 ms ，GC Workers：4]
[队列修正（毫秒）：最小值：0.0，平均值：0.0，最大值：0.0，差值：0.0，总和：0.0]
[Table Fixup（ms）
[其他：9.3 ms]
[选择CSet：0.0 ms]
[Clear CT：0.1 ms]
[1.9：1.9，最大值：1.9，Diff：0.1，
[Ref Proc：8.8 ms]
[累加卡数：0.0 ms]
[Humongous Reclaim：0.0 ms]
[Free CSet：0.1 ms]
[Eden：215.0M 215.0M） - > 0.0B（19.0M）幸存者：7168.0K-> 6144.0K堆：443.6M（512.0M） - > 228.2M（512.0M）]
[时间：用户= 0.30 sys = 0.01，实际= 0.10秒]
2015-05-31T18：26：03.848 + 0200：83422.597：[GC并发字符串重复删除，160.0B-> 0.0B（160.0B），平均48.3％ 0.0123951秒]
[最后执行：0.0123951秒，空闲：38.7017788秒，阻止：0 / 0.0000000秒]
[检查：3]
[跳过：0（0.0％）]
[Hashed：3（100.0％）]
[已知：0（0.0％）]
[New：3（100.0％）160.0B]
[Deduplicated：3（100.0％ ）160.0B（100.0％）]
[年轻：3（100.0％）160.0B（100.0％）]
[旧：0（0.0％）0.0B（0.0％）]
[总执行：2869 / 0.2070075秒，空闲：2869 / 83421.6719550秒，阻止：13 / 0.0032760秒]
[检查：304496]
[跳过：0（0.0％）]
[163711（53.8％）]
[已知：44808（14.7％）]
[新增：259688（85.3％）2190万]
[重复删除：160470（61.8％）10.6百万（48.3％）]
[年龄：83549（52.1％）6270.8K（57.8％）]
[年龄：76921（47.9％）4571.3K（42.2％）]
[
[参赛作品：81061，负载：123.7％，缓存：6553，加入：142396，已移除：61335]
[大小：65536，最小：1024，最大：16777216] [调整大小计数：8，缩小阈值：43690（66.7％），增长阈值：131072（200.0％）]
[Rehash Count：0，Rehash Threshold：120，Hash Seed：0x0]
[Age门槛：3]
[队列]
[掉落：0]
2015-05-31T18：26：05.769 + 0200：83424.518：[GC暂停（G1撤退暂停）（ GC工作人员开始（ms）：最小：83424518.3，平均：83424518.3，最大：83424518.3，差异：0.0] [b] [b]
[Ext Root Scanning（ms）：Min：1.2，Avg：1.6，Max：2.6，Diff：1.4，Sum：6.5]
[更新RS（ms）：Min：0.0，Avg：0.3 ，最大值：0.4，差值：0.4，总和：1.2]
[处理的缓冲区：最小值：0，平均值：4.3，最大值：7，差值：7，总和值：17]
[Scan RS ）：Min：56.1，Avg：102.3，Max：144.4，Diff：88.3，Sum：409.2]
[代码根扫描（ms）：Min：0.0，Avg：0.1，Max：0.2，Diff：0.2， Sum：0.3]
[Object Copy（ms）：Min：50.4，Avg：97.6，Max：157.7，Diff：107.2，Sum：390.2]
[终止值（ms）：Min：0.0，Avg ：14.8，最大值：19.8，差值：19.8，总和：59.1]
[GC Worker Other（ms）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.1]
[GC Worker Total（ms）：Min：216.6，Avg：216.6，Max：216.6，Diff：0.0，Sum：866.5]
[GC Worker End（ms）：Min：83424734.9，Avg：83424734
[Code Root Fixup：0.1 ms]
[代码根净化：0.0 ms]
[String Dedup Fixup：1.5 ms，GC Workers： （ms）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.0]
[Table Fixup（ms）：Min：1.4，Avg：
[其他：4.8毫秒]
[选择CSet：0.0 ms]
[最大值：1.4，差值：0.0，总和：5.6]
[清除CT：0.2 ms]
[Ref Enq：0.0 ms]
[Redirty Cards：0.2 ms]
[Humongous Reclaim：0.0 ms]
[Free CSet：0.2 ms （512.0M）]> 175.2M（512.0M）]
[Eden：19.0M（19.0M） - > 0.0B（21.0M）幸存者：6144.0K-> 4096.0K堆：247.2M
[Times：user = 0.09 sys = 0.00，real = 0.22 secs]
2015-05-31T18：26：05.992 + 0200：83424.742：[GC concurrent-string-deduplication，640.0B->
[最后执行：0.0000246秒，空闲：2.1442834秒，阻止：0 / 0.0000000秒]
[检查：6]
[152.0B[已跳过：0（0.0％）]
[已散列：5（83.3％）]
[已知：0（0.0％）]
[新：6（100.0％）640.0B]
[减重：5（83.3％）488.0B（76.3％）]
[年轻：5（100.0％）488.0B（100.0％）]
[旧：0（0.0％） 0.0B（0.0％）]
[总执行：2870 / 0.2070321秒，空闲：2870 / 83423.8162384秒，阻止：13 / 0.0032760秒]
[检查：304502]
[跳过： 0（0.0％）]
[刷新：163716（53.8％）]
[已知：44808（14.7％）]
[新：259694（85.3％）2190万] b [减重：160475（61.8％）10.6M（48.3％）]
[年轻：83554（52.1％）6271.2K（57.8％）]
[旧：76921（47.9％）4571.3 42.2％）]
[表]
[内存使用量：2564.6K]
[大小：
[条目：81026，负载：123.6％，缓存：6553，已添加：142397，已删除：61371]
[调整大小计数：8，收缩阈值：43690 （66.7％），增长阈值：131072（200.0％）]
[Rehash Count：0，Rehash Threshold：120，Hash Seed：0x0]
[年龄阈值：3]
[队列]
[掉落：0]
2015-05-31T18：26：08.157 + 0200：83426.906：[GC暂停（G1撤退暂停）（混合），0.6216666秒]
[Parallel Time ：618.5 ms，GC Workers：4]
[GC Worker Start（ms）：Min：83426906.5，Avg：83426906.5，Max：83426906.5，Diff：0.0]
[Ext Root Scanning（ms） ：0.3，Avg：8.0，Max：15.7，Diff：15.3，Sum：31.9]
[更新RS（ms）：Min：0.0，Avg：4.5，Max：8.5，Diff：8.5，Sum：17.9]
[已处理的缓冲区：最小值：0，平均值：7.0，最大值：18，差值：18，总和值：28]
[扫描RS（ms）：最小值：13.4，平均值：28.4，最大值：65.2 ，Diff：51.8，Sum：113.7]
[Code Root Scanning（ms）：Min：0.0，Avg：0.0，Max：0.1， Diff：0.1，Sum：0.2]
[Object Copy（ms）：Min：532.6，Avg：577.3，Max：604.5，Diff：71.9，Sum：2309.1]
[Termination（ms） ：0.0，Avg：0.2，Max：0.3，Diff：0.3，Sum：0.7]
[GC Worker Other（ms）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.1 ]
[GC Worker Total（ms）：Min：618.4，Avg：618.4，Max：618.4，Diff：0.0，Sum：2473.6]
[
[代码根固定：0.1 ms]
[代码根净化：0.0 ms]
[String Dedup Fixup：1.3 ms，GC Workers： 4]
[Table Fixup（ms）：Min：1.2，Avg：0.0，0.0：
[其他：1.6 ms]
[选择CSet：0.0 ms]
[最大值：1.3，差值：0.1，总和：4.9]
[清除CT：0.1 ms]
[Ref Enq：0.0 ms]
[Redirty Cards：0.0 ms]
[Humongous Reclaim：0.0 ms]
[Free CSet：0.2 ms ]
[Eden：21.0M（21.0M） - > 0.0B（21.0M）幸存者：4096.0K-> 4096.0K堆：196.2M（512.0M）→129.4M（512.0M）]
[ Times：user = 0.08 sys = 0.02，real = 0.62 secs]
编辑：几个小时后的结果：
有很多页/秒和页面输入/秒以及页面错误。这是正常的吗？我在哪里可以设置监控页面/秒和页面输入/秒为JVM（我只发现页面错误）？
解决方案
我猜你在吠叫错误的树 - 我怀疑垃圾收集不是你的问题......
你只运行一个512 MiB的堆 - 我，一个长时间的停顿，一个大小为1或2秒的堆。巨大的（32 GiB）堆可能会在几毫秒内出现大的暂停。
我期望这个问题实际上是与您的服务器相关 - 无论您的其他应用程序提到的是使用足够的内存将Java进程（比堆大50％）推入交换/虚拟内存 - 或者在虚拟化环境中运行应用程序（可能存在内存过度分配/内存溢出问题）。
作为一个非常粗略的指标，任何GC算法都应该能够每秒钟处理100MB的堆 - 所以如果你看到比这更糟的话，问题的原因。
在这种情况下，我认为GC是症状，而不是问题。
In the last few weeks I have been testing different JVM setting for my Glassfish server. The main settings for heap (among others) are: -Xms512m, -Xmx512m, -XX:NewRatio=2. I tried different GC setting but I still have problems with long pauses after few days from starting server. I noticed following:
1. -XX:+UseParallelGC -XX:+UseParallelOldGC - minor GC were occuring about every minute, major GC every 18 hours. I had no problems with minor GC but there were problems with major GC after 5 days. At first major GC pauses lasted about 100-200ms but at the end the last pause lasted 70 seconds.
2. -XX:+UseConcMarkSweepGC -XX:+UseParNewGC - almost same as the above. Minor GC were fine, but major GC (not full) pauses were getting very long. I noticed problems with high class unloading at GC (CMS Final Remark) phase which is stop the world phase.
3. -XX:+UseConcMarkSweepGC -XX:+UseParNewGC and -XX:MaxGCPauseMillis=5000. I was testing this for only a day because the second major GC last (not full) already lasted for about 20 seconds so I thought there is something else wrong.
4. -XX:+UseG1GC, -XX:MaxGCPauseMillis=5000, -XX:+UseStringDeduplication without -XX:NewRatio=2 option - the major GC (not full) is occurring every 12 hours, I have noticed some problems already:
2015-05-31T18:25:25.145+0200: 83383.897: [GC concurrent-mark-start]
2015-05-31T18:25:35.563+0200: 83394.312: [GC concurrent-mark-end, 10.4145795 secs]
2015-05-31T18:25:35.563+0200: 83394.312: [GC remark 83394.312: [Finalize Marking, 0.0002939 secs] 83394.312: [GC ref-proc, 1.2128584 secs] 83395.525: [Unloading, 14.5180500 secs], 15.7320854 secs]
[Times: user=0.14 sys=0.22, real=15.73 secs]
GC remark phase took 15 seconds which is not acceptable for me. You can see that unloading took most of the time. That also happened before when using other GC so I think there must be problem with class unloading.
Summary: all GC run OK for some time but after few days problems started to appear with long pause times. I don't know why it is working fine first few days and then suddenly the results are very bad. I noticed that higher pause time was caused by class unloading so I am wondering if there are some setting to get better results. Also I want to know which GC are you recommending to me to use? I have internal web application running on glassfish server on PC with 8gb of RAM, i7 processor and with Windows 8 operating system. There will be max 10 clients connection at same time but it must have long uptime and there can not be long pause times (max 5 seconds). Please advise me what else I can do to get shorter pause times.
And one more question: what could be disadvantage using G1GC instead of CMS or ParallelGC in my case? Is the heap to small to use G1GC?
EDIT: G1GC log right before and after long pause GC remark phase
2015-05-31T18:25:25.004+0200: 83383.755: [GC pause (G1 Evacuation Pause) (young) (initial-mark), 0.1280453 secs]
[Parallel Time: 116.2 ms, GC Workers: 4]
[GC Worker Start (ms): Min: 83383757.6, Avg: 83383757.7, Max: 83383757.7, Diff: 0.0]
[Ext Root Scanning (ms): Min: 97.8, Avg: 98.3, Max: 98.5, Diff: 0.7, Sum: 393.1]
[Update RS (ms): Min: 0.2, Avg: 4.0, Max: 14.8, Diff: 14.6, Sum: 16.1]
[Processed Buffers: Min: 1, Avg: 6.0, Max: 16, Diff: 15, Sum: 24]
[Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Object Copy (ms): Min: 0.2, Avg: 2.5, Max: 3.7, Diff: 3.5, Sum: 10.2]
[Termination (ms): Min: 0.0, Avg: 8.5, Max: 11.4, Diff: 11.4, Sum: 34.2]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[GC Worker Total (ms): Min: 113.4, Avg: 113.4, Max: 113.5, Diff: 0.0, Sum: 453.8]
[GC Worker End (ms): Min: 83383871.1, Avg: 83383871.1, Max: 83383871.1, Diff: 0.0]
[Code Root Fixup: 0.1 ms]
[Code Root Purge: 0.0 ms]
[String Dedup Fixup: 2.2 ms, GC Workers: 4]
[Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Table Fixup (ms): Min: 2.0, Avg: 2.1, Max: 2.1, Diff: 0.1, Sum: 8.3]
[Clear CT: 0.1 ms]
[Other: 9.5 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 8.8 ms]
[Ref Enq: 0.1 ms]
[Redirty Cards: 0.3 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.1 ms]
[Eden: 215.0M(215.0M)->0.0B(215.0M) Survivors: 7168.0K->7168.0K Heap: 451.5M(512.0M)->236.6M(512.0M)]
[Times: user=0.08 sys=0.02, real=0.13 secs]
2015-05-31T18:25:25.129+0200: 83383.883: [GC concurrent-root-region-scan-start]
2015-05-31T18:25:25.129+0200: 83383.883: [GC concurrent-string-deduplication, 160.0B->0.0B(160.0B), avg 48.3%, 0.0000070 secs]
[Last Exec: 0.0000070 secs, Idle: 23.1834927 secs, Blocked: 0/0.0000000 secs]
[Inspected: 3]
[Skipped: 0( 0.0%)]
[Hashed: 3(100.0%)]
[Known: 0( 0.0%)]
[New: 3(100.0%) 160.0B]
[Deduplicated: 3(100.0%) 160.0B(100.0%)]
[Young: 3(100.0%) 160.0B(100.0%)]
[Old: 0( 0.0%) 0.0B( 0.0%)]
[Total Exec: 2868/0.1946124 secs, Idle: 2868/83382.9701762 secs, Blocked: 13/0.0032760 secs]
[Inspected: 304493]
[Skipped: 0( 0.0%)]
[Hashed: 163708( 53.8%)]
[Known: 44808( 14.7%)]
[New: 259685( 85.3%) 21.9M]
[Deduplicated: 160467( 61.8%) 10.6M( 48.3%)]
[Young: 83546( 52.1%) 6270.6K( 57.8%)]
[Old: 76921( 47.9%) 4571.3K( 42.2%)]
[Table]
[Memory Usage: 4291.8K]
[Size: 131072, Min: 1024, Max: 16777216]
[Entries: 133319, Load: 101.7%, Cached: 6107, Added: 142389, Removed: 9070]
[Resize Count: 7, Shrink Threshold: 87381(66.7%), Grow Threshold: 262144(200.0%)]
[Rehash Count: 0, Rehash Threshold: 120, Hash Seed: 0x0]
[Age Threshold: 3]
[Queue]
[Dropped: 0]
2015-05-31T18:25:25.145+0200: 83383.897: [GC concurrent-root-region-scan-end, 0.0140467 secs]
2015-05-31T18:25:25.145+0200: 83383.897: [GC concurrent-mark-start]
2015-05-31T18:25:35.563+0200: 83394.312: [GC concurrent-mark-end, 10.4145795 secs]
2015-05-31T18:25:35.563+0200: 83394.312: [GC remark 83394.312: [Finalize Marking, 0.0002939 secs] 83394.312: [GC ref-proc, 1.2128584 secs] 83395.525: [Unloading, 14.5180500 secs], 15.7320854 secs]
[Times: user=0.14 sys=0.22, real=15.73 secs]
2015-05-31T18:25:51.288+0200: 83410.045: [GC cleanup 334M->326M(512M), 0.2836092 secs]
[Times: user=0.00 sys=0.00, real=0.28 secs]
2015-05-31T18:25:51.570+0200: 83410.328: [GC concurrent-cleanup-start]
2015-05-31T18:25:51.570+0200: 83410.328: [GC concurrent-cleanup-end, 0.0000669 secs]
2015-05-31T18:26:03.732+0200: 83422.482: [GC pause (G1 Evacuation Pause) (young), 0.1031257 secs]
[Parallel Time: 91.6 ms, GC Workers: 4]
[GC Worker Start (ms): Min: 83422481.7, Avg: 83422481.7, Max: 83422481.8, Diff: 0.0]
[Ext Root Scanning (ms): Min: 1.3, Avg: 1.7, Max: 2.7, Diff: 1.4, Sum: 6.9]
[Update RS (ms): Min: 0.0, Avg: 22.7, Max: 89.8, Diff: 89.8, Sum: 90.8]
[Processed Buffers: Min: 0, Avg: 7.3, Max: 15, Diff: 15, Sum: 29]
[Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Object Copy (ms): Min: 0.5, Avg: 2.4, Max: 3.4, Diff: 2.9, Sum: 9.5]
[Termination (ms): Min: 0.0, Avg: 64.7, Max: 86.3, Diff: 86.3, Sum: 258.9]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
[GC Worker Total (ms): Min: 91.6, Avg: 91.6, Max: 91.6, Diff: 0.0, Sum: 366.3]
[GC Worker End (ms): Min: 83422573.3, Avg: 83422573.3, Max: 83422573.3, Diff: 0.0]
[Code Root Fixup: 0.1 ms]
[Code Root Purge: 0.0 ms]
[String Dedup Fixup: 2.1 ms, GC Workers: 4]
[Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Table Fixup (ms): Min: 1.9, Avg: 1.9, Max: 1.9, Diff: 0.1, Sum: 7.7]
[Clear CT: 0.1 ms]
[Other: 9.3 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 8.8 ms]
[Ref Enq: 0.1 ms]
[Redirty Cards: 0.0 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.1 ms]
[Eden: 215.0M(215.0M)->0.0B(19.0M) Survivors: 7168.0K->6144.0K Heap: 443.6M(512.0M)->228.2M(512.0M)]
[Times: user=0.30 sys=0.01, real=0.10 secs]
2015-05-31T18:26:03.848+0200: 83422.597: [GC concurrent-string-deduplication, 160.0B->0.0B(160.0B), avg 48.3%, 0.0123951 secs]
[Last Exec: 0.0123951 secs, Idle: 38.7017788 secs, Blocked: 0/0.0000000 secs]
[Inspected: 3]
[Skipped: 0( 0.0%)]
[Hashed: 3(100.0%)]
[Known: 0( 0.0%)]
[New: 3(100.0%) 160.0B]
[Deduplicated: 3(100.0%) 160.0B(100.0%)]
[Young: 3(100.0%) 160.0B(100.0%)]
[Old: 0( 0.0%) 0.0B( 0.0%)]
[Total Exec: 2869/0.2070075 secs, Idle: 2869/83421.6719550 secs, Blocked: 13/0.0032760 secs]
[Inspected: 304496]
[Skipped: 0( 0.0%)]
[Hashed: 163711( 53.8%)]
[Known: 44808( 14.7%)]
[New: 259688( 85.3%) 21.9M]
[Deduplicated: 160470( 61.8%) 10.6M( 48.3%)]
[Young: 83549( 52.1%) 6270.8K( 57.8%)]
[Old: 76921( 47.9%) 4571.3K( 42.2%)]
[Table]
[Memory Usage: 2565.5K]
[Size: 65536, Min: 1024, Max: 16777216]
[Entries: 81061, Load: 123.7%, Cached: 6553, Added: 142396, Removed: 61335]
[Resize Count: 8, Shrink Threshold: 43690(66.7%), Grow Threshold: 131072(200.0%)]
[Rehash Count: 0, Rehash Threshold: 120, Hash Seed: 0x0]
[Age Threshold: 3]
[Queue]
[Dropped: 0]
2015-05-31T18:26:05.769+0200: 83424.518: [GC pause (G1 Evacuation Pause) (mixed), 0.2232916 secs]
[Parallel Time: 216.7 ms, GC Workers: 4]
[GC Worker Start (ms): Min: 83424518.3, Avg: 83424518.3, Max: 83424518.3, Diff: 0.0]
[Ext Root Scanning (ms): Min: 1.2, Avg: 1.6, Max: 2.6, Diff: 1.4, Sum: 6.5]
[Update RS (ms): Min: 0.0, Avg: 0.3, Max: 0.4, Diff: 0.4, Sum: 1.2]
[Processed Buffers: Min: 0, Avg: 4.3, Max: 7, Diff: 7, Sum: 17]
[Scan RS (ms): Min: 56.1, Avg: 102.3, Max: 144.4, Diff: 88.3, Sum: 409.2]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.3]
[Object Copy (ms): Min: 50.4, Avg: 97.6, Max: 157.7, Diff: 107.2, Sum: 390.2]
[Termination (ms): Min: 0.0, Avg: 14.8, Max: 19.8, Diff: 19.8, Sum: 59.1]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
[GC Worker Total (ms): Min: 216.6, Avg: 216.6, Max: 216.6, Diff: 0.0, Sum: 866.5]
[GC Worker End (ms): Min: 83424734.9, Avg: 83424734.9, Max: 83424734.9, Diff: 0.0]
[Code Root Fixup: 0.1 ms]
[Code Root Purge: 0.0 ms]
[String Dedup Fixup: 1.5 ms, GC Workers: 4]
[Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Table Fixup (ms): Min: 1.4, Avg: 1.4, Max: 1.4, Diff: 0.0, Sum: 5.6]
[Clear CT: 0.2 ms]
[Other: 4.8 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.9 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.2 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.2 ms]
[Eden: 19.0M(19.0M)->0.0B(21.0M) Survivors: 6144.0K->4096.0K Heap: 247.2M(512.0M)->175.2M(512.0M)]
[Times: user=0.09 sys=0.00, real=0.22 secs]
2015-05-31T18:26:05.992+0200: 83424.742: [GC concurrent-string-deduplication, 640.0B->152.0B(488.0B), avg 48.3%, 0.0000246 secs]
[Last Exec: 0.0000246 secs, Idle: 2.1442834 secs, Blocked: 0/0.0000000 secs]
[Inspected: 6]
[Skipped: 0( 0.0%)]
[Hashed: 5( 83.3%)]
[Known: 0( 0.0%)]
[New: 6(100.0%) 640.0B]
[Deduplicated: 5( 83.3%) 488.0B( 76.3%)]
[Young: 5(100.0%) 488.0B(100.0%)]
[Old: 0( 0.0%) 0.0B( 0.0%)]
[Total Exec: 2870/0.2070321 secs, Idle: 2870/83423.8162384 secs, Blocked: 13/0.0032760 secs]
[Inspected: 304502]
[Skipped: 0( 0.0%)]
[Hashed: 163716( 53.8%)]
[Known: 44808( 14.7%)]
[New: 259694( 85.3%) 21.9M]
[Deduplicated: 160475( 61.8%) 10.6M( 48.3%)]
[Young: 83554( 52.1%) 6271.2K( 57.8%)]
[Old: 76921( 47.9%) 4571.3K( 42.2%)]
[Table]
[Memory Usage: 2564.6K]
[Size: 65536, Min: 1024, Max: 16777216]
[Entries: 81026, Load: 123.6%, Cached: 6553, Added: 142397, Removed: 61371]
[Resize Count: 8, Shrink Threshold: 43690(66.7%), Grow Threshold: 131072(200.0%)]
[Rehash Count: 0, Rehash Threshold: 120, Hash Seed: 0x0]
[Age Threshold: 3]
[Queue]
[Dropped: 0]
2015-05-31T18:26:08.157+0200: 83426.906: [GC pause (G1 Evacuation Pause) (mixed), 0.6216666 secs]
[Parallel Time: 618.5 ms, GC Workers: 4]
[GC Worker Start (ms): Min: 83426906.5, Avg: 83426906.5, Max: 83426906.5, Diff: 0.0]
[Ext Root Scanning (ms): Min: 0.3, Avg: 8.0, Max: 15.7, Diff: 15.3, Sum: 31.9]
[Update RS (ms): Min: 0.0, Avg: 4.5, Max: 8.5, Diff: 8.5, Sum: 17.9]
[Processed Buffers: Min: 0, Avg: 7.0, Max: 18, Diff: 18, Sum: 28]
[Scan RS (ms): Min: 13.4, Avg: 28.4, Max: 65.2, Diff: 51.8, Sum: 113.7]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2]
[Object Copy (ms): Min: 532.6, Avg: 577.3, Max: 604.5, Diff: 71.9, Sum: 2309.1]
[Termination (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 0.7]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
[GC Worker Total (ms): Min: 618.4, Avg: 618.4, Max: 618.4, Diff: 0.0, Sum: 2473.6]
[GC Worker End (ms): Min: 83427524.9, Avg: 83427524.9, Max: 83427524.9, Diff: 0.0]
[Code Root Fixup: 0.1 ms]
[Code Root Purge: 0.0 ms]
[String Dedup Fixup: 1.3 ms, GC Workers: 4]
[Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Table Fixup (ms): Min: 1.2, Avg: 1.2, Max: 1.3, Diff: 0.1, Sum: 4.9]
[Clear CT: 0.1 ms]
[Other: 1.6 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 1.0 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.0 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.2 ms]
[Eden: 21.0M(21.0M)->0.0B(21.0M) Survivors: 4096.0K->4096.0K Heap: 196.2M(512.0M)->129.4M(512.0M)]
[Times: user=0.08 sys=0.02, real=0.62 secs]
EDIT: Results after few hours:
There is a lot of pages/sec and pages input/sec and also page fault. Is this normal? Where can I set to monitor pages/sec and pages input/sec just for JVM (I only found pages faults)?
解决方案
I'd guess you're barking up the wrong tree - I suspect Garbage Collection is not your problem...
You're only running a 512 MiB heap - to me, a long pause with a heap that size would be 1 or 2 seconds. Major pauses in the milliseconds are possible with huge (32 GiB) heaps.
I'm expecting that the issue is actually with your server - either the other applications you've mentioned are using enough memory to push your Java process (which will be around 50% bigger than the heap) into swap / virtual memory - or you're running your application in a virtualised environment (possibly with memory overcommitment / memory balooning issues).
As a really crude indicator, any GC algorithm should be able to churn though 100 MiB of heap per second - so if you're seeing worse than that, look elsewhere for the cause of the issue.
In this case, I believe GC is the symptom, not the problem.
这篇关于JVM GC问题的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持！