Действительно ли точно указано время «остановить мир», сообщаемое с помощью PrintGCApplicationStoppedTime?

Я пытаюсь оценить, как долго потоки в java-приложении блокируются паузами сборки мусора «остановить мир», используя параметр JVM -XX:+PrintGCApplicationStoppedTime.

Я анализирую файл gc.log и добавляю сообщаемое время остановки к временной метке сборщика мусора (-XX:+PrintGCDateStamps), чтобы получить временные отметки «начало и конец» для событий сборщика мусора.

Потоки приложения измеряют время, необходимое для отправки HTTP-запроса и получения ответа, и регистрируют отметку времени отправки запроса и продолжительность запроса.

Когда я сравниваю метки времени события GC с метками времени приложения (DATA), я получаю некоторые странные результаты:

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. закончился. Моя интерпретация заключается в том, что прошло около 11 мс с момента «освобождения» потоков приложения из безопасной точки до момента, когда сборщик мусора вычислил время «остановить мир».
Верна ли эта интерпретация?

Код в методе SafepointSynchronize::end() в hotspot/src/share/vm/runtime/safepoint.cpp из openjdk, кажется, пробуждает приостановленные потоки Java до рассчитывается время остановки.
Это означает, что заявленное время остановки ненадежно, поток, вычисляющий время остановки, может быть приостановлен между пробуждением потоков Java и вычислением времени, , верно?
(Я не программист на C++, поэтому я мог неправильно интерпретировать код.)

Приложение было запущено с Oracle JDK 1.6.0_20 на сервере Solaris 10 5/08 x86.

Командная строка:

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

7
задан ola 9 March 2012 в 09:47
поделиться