這篇文章分析了為什么Plumbr Agents在某些情況下以及如何延長(zhǎng)GC暫停的時(shí)間。 對(duì)基本問(wèn)題進(jìn)行故障診斷揭示了有關(guān)在GC暫停期間如何處理JVMTI標(biāo)記的有趣見(jiàn)解。

發(fā)現(xiàn)問(wèn)題

我們的一位客戶抱怨說(shuō)，附加了Plumbr代理后，應(yīng)用程序的響應(yīng)速度明顯降低。 通過(guò)分析GC日志，我們發(fā)現(xiàn)GC時(shí)間異常。 這是不帶Plumbr的JVM摘錄的GC日志：

2015-01-30T17:19:08.965-0200: 182.816: [Full GC (Ergonomics) [PSYoungGen: 524800K->0K(611840K)] [ParOldGen: 1102620K->1103028K(1398272K)] 1627420K->1103028K(2010112K), [Metaspace: 2797K->2797K(1056768K)], 0.9563188 secs] [Times: user=7.32 sys=0.01, real=0.96 secs]

這是附加了Plumbr代理的一個(gè)：

2015-02-02T17:40:35.872-0200: 333.166: [Full GC (Ergonomics) [PSYoungGen: 524800K->0K(611840K)] [ParOldGen: 1194734K->1197253K(1398272K)] 1719534K->1197253K(2010112K), [Metaspace: 17710K->17710K(1064960K)], 1.9900624 secs] [Times: user=7.94 sys=0.01, real=1.99 secs]

異常隱藏在經(jīng)過(guò)的時(shí)間中。 實(shí)時(shí)時(shí)間是經(jīng)過(guò)的實(shí)際時(shí)間。 如果您手里拿著秒表，那么實(shí)時(shí)將等于該數(shù)字。 用戶時(shí)間 （加上系統(tǒng)時(shí)間）是測(cè)量過(guò)程中消耗的總CPU時(shí)間。 如果多個(gè)內(nèi)核上有多個(gè)線程，則該時(shí)間可能大于實(shí)時(shí)時(shí)間。 因此，對(duì)于并行GC，實(shí)時(shí)時(shí)間應(yīng)大致等于（用戶時(shí)間/線程數(shù)）。 在我的機(jī)器上，該比率應(yīng)該接近7，而沒(méi)有Plumbr Agent的情況下確實(shí)是如此。 但是使用Plumbr時(shí)，該比率大大下降。 絕對(duì)不行！

初步調(diào)查

有了這樣的證據(jù)，以下是最可能的假設(shè)：

Plumbr導(dǎo)致JVM在每個(gè)GC之后執(zhí)行一些繁重的單線程操作

Plumbr導(dǎo)致JVM使用更少的線程進(jìn)行垃圾回收

但是，僅查看GC日志中的一行，就無(wú)法進(jìn)行更狹窄的觀察，因此我們繼續(xù)進(jìn)行可視化上述比率：

圖表上的下降恰好發(fā)生在Plumbr發(fā)現(xiàn)內(nèi)存泄漏的那一刻。 在根本原因分析過(guò)程中，GC可能會(huì)給GC帶來(lái)一些額外負(fù)擔(dān)，但永久影響GC暫停時(shí)間絕對(duì)不是我們?yōu)榇硖匾庠O(shè)計(jì)的功能。 這種行為有利于第一個(gè)假設(shè)，因?yàn)槲覀儾惶赡茉谶\(yùn)行時(shí)影響GC線程的數(shù)量。

創(chuàng)建隔離的測(cè)試用例花費(fèi)了一段時(shí)間，但是在以下約束的幫助下，我們可以釘上它：

應(yīng)用程序必須泄漏內(nèi)存以供Plumbr檢測(cè)

應(yīng)用程序必須經(jīng)常暫停以進(jìn)行垃圾收集

…以及作為突破時(shí)刻–應(yīng)用程序必須具有較大的活動(dòng)集，這意味著在Full GC中幸存的對(duì)象數(shù)量必須很大。

在編譯了足夠小的測(cè)試用例之后，可以放大根本原因檢測(cè)范圍。 合理的方法是打開(kāi)和關(guān)閉Plumbr代理的各個(gè)功能，并查看問(wèn)題將在哪種配置下重現(xiàn)。

通過(guò)這種簡(jiǎn)單的搜索，我們?cè)O(shè)法將問(wèn)題定位到Plumbr Agent執(zhí)行的單個(gè)操作。 關(guān)閉JVMTI標(biāo)簽后，問(wèn)題消失了。 在分析gc根和引用鏈的路徑時(shí) ，我們標(biāo)記堆上的每個(gè)對(duì)象。 顯然，GC時(shí)間在某種程度上受我們生成的標(biāo)簽的影響。

尋找根本原因

不過(guò)，尚不清楚為什么GC暫停會(huì)延長(zhǎng)。 垃圾會(huì)被Swift收集，并且大多數(shù)帶標(biāo)簽的對(duì)象都應(yīng)該符合GC的條件。 但是發(fā)現(xiàn)的是，存在大量活動(dòng)集（這是內(nèi)存泄漏的癥狀之一），其中保留了許多帶標(biāo)簽的對(duì)象。

但是，即使對(duì)活動(dòng)集中的所有對(duì)象都進(jìn)行了標(biāo)記，這也不應(yīng)線性影響GC時(shí)間。 GC完成后，我們會(huì)收到有關(guān)所有已收集的標(biāo)記對(duì)象的通知，但活動(dòng)集不在這些對(duì)象之內(nèi)。 這使人們想知道，HotSpot是否出于某種奇怪的原因在每個(gè)GC之后迭代所有標(biāo)記的對(duì)象。

為了驗(yàn)證索賠，可以查看熱點(diǎn)源代碼。 經(jīng)過(guò)一番挖掘之后，我們最終到達(dá)了JvmtiTagMap :: do_weak_oops ，它的確遍歷了所有標(biāo)簽，并對(duì)所有標(biāo)簽進(jìn)行了一些不太便宜的操作。 更糟的是，該操作是順序執(zhí)行的，并且不并行執(zhí)行。 在找到每個(gè)垃圾回收之后調(diào)用此方法的調(diào)用鏈之后，解決了最后一個(gè)難題。 （為什么這樣做的方式以及它與弱引用的關(guān)系完全超出了本文的范圍）

在并行GC上運(yùn)行并具有與串行運(yùn)行相同的昂貴操作，一開(kāi)始似乎是設(shè)計(jì)缺陷。 第二個(gè)想法，JVMTI的創(chuàng)建者可能從未期望有人標(biāo)記所有的堆，因此從來(lái)沒(méi)有費(fèi)心去優(yōu)化此操作或并行運(yùn)行它。 畢竟，您永遠(yuǎn)無(wú)法預(yù)測(cè)人們將使用您設(shè)計(jì)的功能的所有方式，因此也許值得檢查一下Hotspot中的GC后活動(dòng)是否也應(yīng)該有機(jī)會(huì)使用現(xiàn)代JVM傾向于使用的所有g(shù)azillion內(nèi)核?？墒褂?。

因此，為了解決這個(gè)問(wèn)題，我們需要清理不再需要的標(biāo)簽。 修復(fù)它就像在我們的JVMTI回調(diào)之一中僅添加三行一樣容易：

+ if(isGenerated(*tag_ptr)) { + *tag_ptr = 0; + }

而且瞧瞧，一旦分析完成，我們幾乎和開(kāi)始時(shí)一樣出色。 如下面的屏幕快照所示，在發(fā)現(xiàn)內(nèi)存泄漏期間仍然存在暫時(shí)的性能波動(dòng)，并且在完成內(nèi)存泄漏分析之后會(huì)略有惡化：

包起來(lái)

現(xiàn)在，補(bǔ)丁已推出，并且解決了Plumbr檢測(cè)到泄漏后GC暫停時(shí)間受到影響的情況。 隨意去獲取更新的代理以解決性能問(wèn)題。

作為一個(gè)總結(jié)，我建議您在使用廣泛的標(biāo)簽時(shí)要格外小心，因?yàn)椤氨阋恕钡臉?biāo)簽會(huì)堆積在角落的箱子上，從而為性能的大幅下降奠定了基石。 為確保您沒(méi)有濫用標(biāo)記，請(qǐng)翻轉(zhuǎn)– XX：+ TraceJVMTIObjectTagging的診斷選項(xiàng)。 它將使您能夠估計(jì)標(biāo)簽映射消耗多少本機(jī)內(nèi)存以及堆遍歷花費(fèi)的時(shí)間。

翻譯自: https://www.javacodegeeks.com/2015/02/jvmti-tagging-can-affect-gc-pauses.html

總結(jié)

以上是生活随笔為你收集整理的JVMTI标记如何影响GC暂停的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問(wèn)題。

如果覺(jué)得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。