PrintGCApplicationStoppedTimeで報告された「世界を止める」時間は本当に正確ですか？

Question

-XX：+ PrintGCApplicationStoppedTime JVMオプションを使用して、Javaアプリケーションのスレッドがガベージコレクションによってブロックされる時間を推定しようとしています。

gc.logファイルを解析し、報告された停止時間をGCタイムスタンプ（-XX：+ PrintGCDateStamps）に追加して、GCイベントのタイムスタンプを「開始および停止」します。

アプリケーション・スレッドは、HTTPリクエストを送信し、応答を取得し、リクエストが送信され、要求の継続されたときにタイムスタンプを記録するのにかかる時間を測定します。

、私はいくつかの奇妙な結果を得る（DATA）のタイムスタンプアプリケーションでGCイベントのタイムスタンプを比較すると：

 
Type| Start time|Start time diff|  End time|End time diff| Duration 
DATA|1330360259830|   230|1330360260139|   7|  309 
DATA|1330360259849|   211|1330360260138|   8|  289 
DATA|1330360259960|   100|1330360260135|   11|  175 
DATA|1330360259979|    81|1330360260135|   11|  156 
DATA|1330360259980|    80|1330360260135|   11|  155 
DATA|1330360259989|    71|1330360260135|   11|  146 
DATA|1330360260019|    41|1330360260135|   11|  116 
DATA|1330360260029|    31|1330360260135|   11|  106 
    GC|1330360260060|    0|1330360260146|   0|  86 

上記の「奇数」の部分が「DATA」のエントリのほとんどが11に終了したということですGCイベントが終了する前のms。 私の解釈は、GCが「世界を止める」時間を計算するまで、アプリケーションスレッドが安全ポイントから「解放」されてから約11ミリ秒かかることです。
この解釈は正しいですか？

のOpenJDKからの方法hotspot/src/share/vm/runtime/safepoint.cppでSafepointSynchronize::end()のコードは、停止時間が計算される前に中断したJavaスレッドを覚ますようです。
報告停止時間が信頼できないであることを意味し、停止時間を計算するスレッドはは右、Javaスレッドを起床し、時間を計算する間に懸架なるのでしょうか？
（私はC++プログラマではないので、コードを誤解している可能性があります）

Solaris 10 5/08 x86サーバーでOracle JDK 1.6.0_20を使用してアプリケーションを実行しました。

コマンドライン：

java -Xss128k -Xms1024m -Xmx1024m -XX:MaxPermSize=28m -Xloggc:logs/gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintTenuringDistribution -XX:+PrintGCApplicationStoppedTime -XX:+PrintHeapAtGC -classpath [...] net.grinder.engine.process.WorkerProcessEntryPoint

Answer 1

これらのフラグは間違って名前が付けられていて、あなたは彼らが信頼できないだったことが正しいです。あなたが従っているバグレポートはthis oneで、hs17で修正され、6u21で最初にヒットしました（this fix list）ので、1バージョンが古すぎます。

とにかくデータが誤って使用されていることにも注意してください。 stoppedtimeフラグにはPrintGCApplicationConcurrentTimeフラグが付いています。これらの2つのフラグが何を出力しているかは、セーフポイントで費やされた時間です。セーフポイントが何であるかについては、PrintSafepointStatisticsを使用できます。

This answerは同様の主題です。