Почему существует несколько журналов «Общее время остановки потоков приложений» между двумя второстепенными GC? - PullRequest
10 голосов
/ 29 июля 2011

Я запускаю Java-приложение со следующими настройками:

-Xms1G -Xmx2G -Xdebug -Xloggc: /usr/local/resin/log/gc.log -XX: + PrintGCDetails-XX: PermSize = 150M -XX: + PrintGCTimeStamps -XX: + PrintTenuringDistribution -XX: + PrintGCApplicationStoppedTime -XX: + PrintGCApplicationConcurrentTime -XX: + PrintHeapAtGC -XX: + UseConcMarkSweepGC

1004 * 100 * * * * *XX: + PrintGCApplicationStoppedTime переключатель будет выводить, сколько раз приложение останавливается каждый раз, когда происходит GC, но получает несколько строк журналов, указывающих, сколько времени приложение останавливается между двумя второстепенными GC, например, следующие журналы:

Total time for which application threads were stopped: 0.0043330 seconds
Application time: 1410.4236260 seconds
{Heap before GC invocations=636 (full 2):
 par new generation   total 38336K, used 34123K [0x00002aaab1a60000, 0x00002aaab43f0000, 0x00002aaab43f0000)
  eden space 34112K, 100% used [0x00002aaab1a60000, 0x00002aaab3bb0000, 0x00002aaab3bb0000)
  from space 4224K,   0% used [0x00002aaab3bb0000, 0x00002aaab3bb2de0, 0x00002aaab3fd0000)
  to   space 4224K,   0% used [0x00002aaab3fd0000, 0x00002aaab3fd0000, 0x00002aaab43f0000)
 concurrent mark-sweep generation total 1006016K, used 208278K [0x00002aaab43f0000, 0x00002aaaf1a60000, 0x00002aab31a60000)
 concurrent-mark-sweep perm gen total 153600K, used 90763K [0x00002aab31a60000, 0x00002aab3b060000, 0x00002aab3b060000)
122682.024: [GC 122682.024: [ParNew
Desired survivor size 2162688 bytes, new threshold 4 (max 4)
- age   1:       4896 bytes,       4896 total
- age   2:       2272 bytes,       7168 total
: 34123K->10K(38336K), 0.0037720 secs] 242402K->208291K(1044352K), 0.0038540 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=637 (full 2):
 par new generation   total 38336K, used 10K [0x00002aaab1a60000, 0x00002aaab43f0000, 0x00002aaab43f0000)
  eden space 34112K,   0% used [0x00002aaab1a60000, 0x00002aaab1a60000, 0x00002aaab3bb0000)
  from space 4224K,   0% used [0x00002aaab3fd0000, 0x00002aaab3fd2bf8, 0x00002aaab43f0000)
  to   space 4224K,   0% used [0x00002aaab3bb0000, 0x00002aaab3bb0000, 0x00002aaab3fd0000)
 concurrent mark-sweep generation total 1006016K, used 208280K [0x00002aaab43f0000, 0x00002aaaf1a60000, 0x00002aab31a60000)
 concurrent-mark-sweep perm gen total 153600K, used 90763K [0x00002aab31a60000, 0x00002aab3b060000, 0x00002aab3b060000)
}
Total time for which application threads were stopped: 0.0044760 seconds
Application time: 317.6313600 seconds
Total time for which application threads were stopped: 0.0004960 seconds
Application time: 86.5483550 seconds
Total time for which application threads were stopped: 0.0005090 seconds
Application time: 0.0001400 seconds
Total time for which application threads were stopped: 0.0001360 seconds
Application time: 46.6827150 seconds
Total time for which application threads were stopped: 0.0004430 seconds
Application time: 74.2952540 seconds
Total time for which application threads were stopped: 0.0004940 seconds
Application time: 0.0001300 seconds
Total time for which application threads were stopped: 0.0001130 seconds
Application time: 0.0001290 seconds
Total time for which application threads were stopped: 0.0001290 seconds
Application time: 51.1991810 seconds
Total time for which application threads were stopped: 0.0004860 seconds
Application time: 190.7426760 seconds
Total time for which application threads were stopped: 0.0004930 seconds
Application time: 0.0000750 seconds
Total time for which application threads were stopped: 0.0001000 seconds
Application time: 55.4635280 seconds
Total time for which application threads were stopped: 0.0004900 seconds
Application time: 180.7308270 seconds
Total time for which application threads were stopped: 0.0005060 seconds
Application time: 60.9953830 seconds
Total time for which application threads were stopped: 0.0005490 seconds
Application time: 60.9591480 seconds
Total time for which application threads were stopped: 0.0006410 seconds
Application time: 292.0577720 seconds
{Heap before GC invocations=637 (full 2):
 par new generation   total 38336K, used 34122K [0x00002aaab1a60000, 0x00002aaab43f0000, 0x00002aaab43f0000)
  eden space 34112K, 100% used [0x00002aaab1a60000, 0x00002aaab3bb0000, 0x00002aaab3bb0000)
  from space 4224K,   0% used [0x00002aaab3fd0000, 0x00002aaab3fd2bf8, 0x00002aaab43f0000)
  to   space 4224K,   0% used [0x00002aaab3bb0000, 0x00002aaab3bb0000, 0x00002aaab3fd0000)
 concurrent mark-sweep generation total 1006016K, used 208280K [0x00002aaab43f0000, 0x00002aaaf1a60000, 0x00002aab31a60000)
 concurrent-mark-sweep perm gen total 153600K, used 90763K [0x00002aab31a60000, 0x00002aab3b060000, 0x00002aab3b060000)
124099.341: [GC 124099.341: [ParNew
Desired survivor size 2162688 bytes, new threshold 4 (max 4)
- age   1:      20680 bytes,      20680 total
- age   3:        808 bytes,      21488 total
: 34122K->25K(38336K), 0.0036900 secs] 242403K->208305K(1044352K), 0.0037700 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Heap after GC invocations=638 (full 2):
 par new generation   total 38336K, used 25K [0x00002aaab1a60000, 0x00002aaab43f0000, 0x00002aaab43f0000)
  eden space 34112K,   0% used [0x00002aaab1a60000, 0x00002aaab1a60000, 0x00002aaab3bb0000)
  from space 4224K,   0% used [0x00002aaab3bb0000, 0x00002aaab3bb6488, 0x00002aaab3fd0000)
  to   space 4224K,   0% used [0x00002aaab3fd0000, 0x00002aaab3fd0000, 0x00002aaab43f0000)
 concurrent mark-sweep generation total 1006016K, used 208280K [0x00002aaab43f0000, 0x00002aaaf1a60000, 0x00002aab31a60000)
 concurrent-mark-sweep perm gen total 153600K, used 90763K [0x00002aab31a60000, 0x00002aab3b060000, 0x00002aab3b060000)
}

Почему существует несколько последовательных строк «Общее время, за которое потоки приложений были остановлены» и «Время приложения» между двумя второстепенными GC.С чем связана каждая из них?GC, который не выводится подробно?или они не вызваны GC?

Если я хочу узнать общее время, в течение которого мое приложение остановилось во время GC, я должен суммировать время во всех этих журналах?

Ответы [ 2 ]

4 голосов
/ 07 августа 2011

Используйте -XX:+PrintSafepointStatistics, чтобы узнать причину каждой безопасной точки, ссылки в этот ответ показывают, где можно получить полный список того, что может привести к достижению безопасной точки.

1 голос
/ 29 июля 2011

Этот журнал показывает каждую причину остановки приложения, а не только для сборщиков мусора.Один из способов уменьшить это - отключить смещенную блокировку (ничего общего с ГХ);)

Попробуйте

-XX:-UseBiasedLocking
Добро пожаловать на сайт PullRequest, где вы можете задавать вопросы и получать ответы от других членов сообщества.
...