奇怪的小gc發生後，正常小gc

2013-11-26T10:19:30.011+0800: [GC [ParNew: 2432484K->19997K(2696640K), 0.0378270 secs] 5560240K->3155822K(7691712K), 0.0398670 secs] [Times: user=0.18 sys=0.00, real=0.04 secs] 
2013-11-26T10:19:36.277+0800: [GC [ParNew: 2417093K->15777K(2696640K), 0.0372550 secs] 5552917K->3151795K(7691712K), 0.0388490 secs] [Times: user=0.28 sys=0.00, real=0.04 secs] 
**2013-11-26T10:19:36.325+0800: [GC [ParNew: 20441K->16452K(2696640K), 0.0186420 secs] 3156459K->3153092K(7691712K), 0.0200280 secs] [Times: user=0.17 sys=0.00, real=0.02 secs]** 
2013-11-26T10:19:41.464+0800: [GC [ParNew: 2413508K->22811K(2696640K), 0.0426440 secs] 5550148K->3160128K(7691712K), 0.0444710 secs] [Times: user=0.25 sys=0.00, real=0.04 secs]

顯然小gc每5或6秒發生。奇怪的小gc發生後，正常小gc

2013-11-26T10：19：36.277之後，在2013-11-26T10：19：36.325有一個小小的gc，只有20441K被使用！

爲什麼小gc發生了（上面的線）？誰知道？

更多detais：

這種現象僅發生每24小時不超過10倍。

有關於我們的服務器的詳細信息：

CPU計數12個CPU

CPU速度的2400MHz

內存總容量16322984 KB

JVM的ARGS（熱點1.6.0_26）是：

-Xms7804M -Xmx7804M -Xmn2926M -XX：PermSize = 256M -XX：MaxPermSize = 256M -XX：SurvivorRatio = 8 -XX：TargetSurvivorRatio = 70 -XX：MaxTen uringThreshold = 10 -server -Xss256k -XX：+ HeapDumpOnOutOfMemoryError -XX：+ PrintGCDetails -XX：+ PrintGCDateStamps -XX：+ UseConcMarkSweepGC -XX：+ DisableExplicitGC -XX：SoftRefLRUPolicyMSPerMB = 0 -XX：CMSInitiatingOccupancyFraction = 75 -XX：+ UseCMSInitiatingOccupancyOnly - XX：ParallelGCThreads = 12 -XX：+ CMSScavengeBeforeRemark -XX：+ CMSClassUnloadingEnabled

@Alexey Ragozin多個日誌：

2013-11-27T23:34:47.352+0800: [GC [ParNew: 2496458K->81521K(2696640K), 0.0381510 secs]  5104803K->2690529K(7691712K), 0.0406260 secs] [Times: user=0.28 sys=0.00, real=0.04 secs] 
2013-11-27T23:34:51.745+0800: [GC [ParNew: 2478577K->57599K(2696640K), 0.0535680 secs] 5087585K->2716762K(7691712K), 0.0554400 secs] [Times: user=0.28 sys=0.01, real=0.06 secs] 
2013-11-27T23:34:55.728+0800: [GC [ParNew: 2454747K->19841K(2696640K), 0.0300150 secs] 5113910K->2679701K(7691712K), 0.0320030 secs] [Times: user=0.18 sys=0.00, real=0.03 secs] 
**2013-11-27T23:34:55.769+0800: [GC [ParNew: 21438K->16389K(2696640K), 0.0171200 secs] 2681299K->2676788K(7691712K), 0.0187850 secs] [Times: user=0.13 sys=0.00, real=0.02 secs]** 
2013-11-27T23:34:59.888+0800: [GC [ParNew: 2413445K->16017K(2696640K), 0.0251400 secs] 5073844K->2676744K(7691712K), 0.0271570 secs] [Times: user=0.15 sys=0.00, real=0.02 secs] 
2013-11-27T23:35:04.374+0800: [GC [ParNew: 2413073K->16059K(2696640K), 0.0240360 secs] 5073800K->2677460K(7691712K), 0.0259960 secs] [Times: user=0.15 sys=0.00, real=0.03 secs] 
... ... 
2013-11-28T02:56:57.719+0800: [GC [ParNew: 2449927K->45500K(2696640K), 0.0360740 secs] 6195838K->3791742K(7691712K), 0.0379370 secs] [Times: user=0.23 sys=0.00, real=0.03 secs] 
2013-11-28T02:57:37.987+0800: [GC [ParNew: 2442556K->54097K(2696640K), 0.0383490 secs] 6188798K->3800678K(7691712K), 0.0402170 secs] [Times: user=0.23 sys=0.00, real=0.04 secs] 
2013-11-28T02:57:38.036+0800: [GC [1 CMS-initial-mark: 3746580K(4995072K)] 3801777K(7691712K), 0.0694940 secs] [Times: user=0.06 sys=0.00, real=0.07 secs] 
2013-11-28T02:57:38.770+0800: [CMS-concurrent-mark: 0.661/0.662 secs] [Times: user=2.15 sys=0.00, real=0.66 secs] 
2013-11-28T02:57:38.806+0800: [CMS-concurrent-preclean: 0.035/0.035 secs] [Times: user=0.06 sys=0.01, real=0.04 secs] 
CMS: abort preclean due to time 2013-11-28T02:57:43.862+0800: [CMS-concurrent-abortable-preclean: 5.016/5.056 secs] [Times: user=6.82 sys=0.19, real=5.05 secs] 
**2013-11-28T02:57:43.872+0800: [GC[YG occupancy: 407766 K (2696640 K)]2013-11-28T02:57:43.872+0800: [GC [ParNew: 407766K->35780K(2696640K), 0.0236470 secs] 4154346K->3782623K(7691712K), 0.0256460 secs] [Times: user=0.20 sys=0.00, real=0.03 secs]** 
[Rescan (parallel) , 0.0119390 secs][weak refs processing, 0.8478360 secs][class unloading, 0.0661530 secs][scrub symbol & string tables, 0.0146780 secs] [1 CMS-remark: 3746843K(4995072K)] 3782623K(7691712K), 1.1138910 secs] [Times: user=1.41 sys=0.00, real=1.12 secs] 
2013-11-28T02:57:48.965+0800: [CMS-concurrent-sweep: 3.893/3.977 secs] [Times: user=5.65 sys=0.15, real=3.97 secs] 
2013-11-28T02:57:48.977+0800: [CMS-concurrent-reset: 0.012/0.012 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]

來源

2013-11-26 yongfei gao

這是什麼語言/環境？世界上有許多*不同的垃圾收集器。 –

這是java。 jvm是熱點1.6.0_26 –

我懷疑任何人，除了人誰寫的和/或維持特定的GC ，可以正確/正確地解釋這種現象。

但是，我會觀察到您的應用程序正在創建非常多的垃圾。 2400000K ==每6秒垃圾2.4Gb。要麼你有病態應用程序，要麼這是一個非常不切實際的垃圾收集器基準測試...，它不會告訴你任何關於GC如何用於實際應用程序的意義。

如果你問這個問題只是爲了滿足你的好奇心，我建議你自己查的現象......然後彙報你的結果作爲自答。

來源

2013-11-26 09:19:54

首先，應用程序在線，而不是beanchmark！其次，服務器上每秒約有27535頁面瀏覽量（我們有42個服務器組成該集羣）。「每6秒垃圾2.4Gb」可能是病理性的。我們將分析後面的堆轉儲以優化應用程序。現在，當調整jvm時，我們發現了奇怪的小gc。所以我問了這個問題，如果您有任何建議，請告訴我，謝謝！ –

我的建議是「忽略它」！對於具有非常大吞吐量（和大量內核）的系統來說，垃圾產生率可能不會過高。但是日誌似乎表示集合需要0.02秒的實時時間......而且小的開銷無關緊要。 –

謝謝！我只是對外觀有些好奇。 –

當年輕一代填滿時發生小GC。如果遵循以高速率創建新對象的應用程序將經歷越來越多的次要垃圾回收。鑑於您發佈的GC日誌，您的應用程序也可以看到完全相同的行爲。您可以高速創建對象，從而經常觸發次要GC。

對於一般GC有關更多信息，你可以給看看這個資源：http://www.oracle.com/webfolder/technetwork/tutorials/obe/java/gc01/index.html

來源

2013-11-26 09:33:14

-XX:+CMSScavengeBeforeRemark是你的怪異次要收集的一個原因。

CMS要做2停止這世界暫停完成舊空間收集週期

初始標記
此言

他們都需要掃描整個年輕的空間。在年輕收藏之後，年輕空間中的物品數量相當小，因此這是一個有益的時間表。舊的空間收藏在年輕收藏之後立即停止。

-XX:+CMSScavengeBeforeRemark只要CMS準備好暫停留言，即使伊甸園尚未滿滿，選項也會迫使年輕人收藏。

你會在每個舊的空間採集週期中看到這個「現象」。

更多關於CMS機制的細節 - 更Understanding GC pauses in JVM, HotSpot's CMS collector
關於JVM GC選項 - HotSpot JVM garbage collection options cheat sheet

UPDATE
從技術上講有可能導致過早年輕GC的另一個原因。如果應用程序嘗試分配不適合Eden的大數組，JVM可能會開始收集以釋放空間。這是可能的，但更有可能的是JVM將選擇直接在舊空間中分配這個數組。

來源

2013-11-27 05:00:38

在添加選項「CMSScavengeBeforeRemark」之前，它已經發生。所以我認爲這不是原因。此外，如果添加「CMSScavengeBeforeRemark」，則較小的gc發生在預清潔階段和備註階段之間，如下所示： 2013-11-27T12：21：47.055 + 0800：[GC [YG入住率：2142008 K（2696640 K）] 2013-11-27T12：21：47.055 + 0800：[GC [ParNew：2142008K-> 22468K（2696640K），0.0246940secs] 5888491K-> 3769345K（7691712K），0.0268340secs] [Times：user = 0.16 sys = 0.00，real = 0.03秒] –

@ user3007751您能否使用新的日誌片段更新您的原始文章？ JVM啓動年輕收集的原因數量有限。備註是其中之一。我添加了另一個原因的描述，但它不太可能是你的情況。 –

我發佈了更多日誌。也許正如@Stephen C所建議的那樣，這是無關緊要的。我只是對外觀有些好奇。 –

奇怪的小gc發生後，正常小gc

回答

相關問題