jvm gc停頓

不同的事件可能導(dǎo)致JVM暫停所有應(yīng)用程序線程。 這種暫停稱為世界停止（STW）暫停。 觸發(fā)STW暫停的最常見(jiàn)原因是垃圾回收（ 例如github中的示例 ），但是不同的JIT操作（ 示例 ），偏向鎖吊銷(xiāo)（ 示例 ），某些JVMTI操作以及更多其他 操作也需要停止應(yīng)用程序。

可以安全停止應(yīng)用程序線程的點(diǎn)稱為“意外點(diǎn)”。 此術(shù)語(yǔ)也經(jīng)常用于指代所有STW暫停。

啟用GC日志或多或少是常見(jiàn)的。 但是，這不會(huì)捕獲所有安全點(diǎn)上的信息。 要獲得全部信息，請(qǐng)使用以下JVM選項(xiàng)：

-XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime

如果您想知道顯式引用GC的命名，請(qǐng)不要驚慌-啟用這些選項(xiàng)會(huì)記錄所有安全點(diǎn)，而不僅僅是垃圾收集暫停。 如果您運(yùn)行下面的示例（ github中的源代碼），并帶有上面指定的標(biāo)志

public class FullGc {private static final Collection<Object> leak = new ArrayList<>();private static volatile Object sink;public static void main(String[] args) {while (true) {try {leak.add(new byte[1024 * 1024]);sink = new byte[1024 * 1024];} catch (OutOfMemoryError e) {leak.clear();}}} }

您應(yīng)該在標(biāo)準(zhǔn)輸出中看到類(lèi)似于以下內(nèi)容的條目：

Application time: 0.3440086 seconds Total time for which application threads were stopped: 0.0620105 seconds Application time: 0.2100691 seconds Total time for which application threads were stopped: 0.0890223 seconds

讀取起來(lái)很容易（尤其是與GC日志進(jìn)行比較）–從上面您可以看到應(yīng)用程序在前344毫秒內(nèi)成功完成了有用的工作，將所有線程暫停了62毫秒，接著是210毫秒的有用工作和89毫秒的暫停。

您可以將這些標(biāo)志與GC標(biāo)志結(jié)合使用，例如，當(dāng)再次運(yùn)行同一程序并添加-XX：+ PrintGCDetails時(shí) ，輸出將類(lèi)似于以下內(nèi)容：

[Full GC (Ergonomics) [PSYoungGen: 1375253K->0K(1387008K)] [ParOldGen: 2796146K->2049K(1784832K)] 4171400K->2049K(3171840K), [Metaspace: 3134K->3134K(1056768K)], 0.0571841 secs] [Times: user=0.02 sys=0.04, real=0.06 secs] Total time for which application threads were stopped: 0.0572646 seconds, Stopping threads took: 0.0000088 seconds

基于以上內(nèi)容，我們看到應(yīng)用程序線程被迫停止57毫秒以進(jìn)行垃圾回收。 等待所有應(yīng)用程序線程到達(dá)安全點(diǎn)所花的時(shí)間為8微秒。 但是，如果我們?cè)倥e一個(gè)示例（ github中的源代碼 ）并使用相同的選項(xiàng)運(yùn)行它，我們可能會(huì)看到以下輸出：

Total time for which application threads were stopped: 0.0001273 seconds, Stopping threads took: 0.0000196 seconds Total time for which application threads were stopped: 0.0000648 seconds, Stopping threads took: 0.0000174 seconds

由此，我們實(shí)際上無(wú)法推斷出導(dǎo)致暫停的原因，因?yàn)闆](méi)有垃圾收集活動(dòng)。 如果您想更詳細(xì)地了解其他安全點(diǎn)，那么這里有幾個(gè)JVM參數(shù)供您選擇：

-XX:+PrintSafepointStatistics ?-XX:PrintSafepointStatisticsCount=1

啟用它們會(huì)使JVM將其他信息記錄到標(biāo)準(zhǔn)輸出中，類(lèi)似于以下內(nèi)容：

5.141: RevokeBias ??????????????????????[ ?????13 ?????????0 ?????????????2 ???] ?????[ ????0 ????0 ????0 ????0 ????0 ???] ?0 ? Total time for which application threads were stopped: 0.0000782 seconds, Stopping threads took: 0.0000269 seconds

根據(jù)以下順序顯示有關(guān)安全點(diǎn)的信息：

• 自JVM啟動(dòng)以來(lái)的時(shí)間戳（以毫秒為單位）（上例中為5.141）
• 觸發(fā)暫停的操作的名稱（ RevokeBias ）。
  • 如果看到“無(wú)虛擬機(jī)操作”，則意味著這是所謂的“保證安全點(diǎn)”。
• 在安全點(diǎn)停止的線程數(shù)（13）
• 在安全點(diǎn)開(kāi)始時(shí)運(yùn)行的線程數(shù)（0）
• vm操作開(kāi)始執(zhí)行時(shí)被阻塞的線程數(shù)（2）
• 到達(dá)安全點(diǎn)和執(zhí)行操作的各個(gè)階段的時(shí)間（全零）

因此，現(xiàn)在我們看到，使用偏向鎖可能會(huì)導(dǎo)致許多STW暫停發(fā)生，即使它們僅花費(fèi)數(shù)十微秒的時(shí)間。 在大量平行的日子里立即禁用它們并不罕見(jiàn)。

總而言之，通過(guò)隨時(shí)記錄這些數(shù)據(jù)，您確實(shí)可以為自己省去一些麻煩。 為此，請(qǐng)指定以下JVM選項(xiàng)：

-XX:+LogVMOutput -XX:LogFile=vm.log

并且所有JVM的輸出都將存儲(chǔ)到vm.log文件中。 但是，基于這些日志進(jìn)行解釋和執(zhí)行是一個(gè)非常廣泛的話題，不在本文的討論范圍之內(nèi)，但是將來(lái)我可能會(huì)寫(xiě)一兩篇有關(guān)它的文章，因此，如有興趣，請(qǐng)隨時(shí)關(guān)注–通過(guò)我們的Twitter訂閱或通過(guò)RSS feed 。

如果您想立即內(nèi)容，請(qǐng)閱讀Nitsan Wakart的精彩博客文章 ：當(dāng)然還有OpenJDK源代碼 。

翻譯自: https://www.javacodegeeks.com/2015/04/logging-stop-the-world-pauses-in-jvm.html

jvm gc停頓

總結(jié)

以上是生活随笔為你收集整理的jvm gc停顿_在JVM中记录世界停顿的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問(wèn)題。

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