GC произвел разъяснение

Я запускаю JAVA-приложение со следующими настройками:
- XX: + CMSParallelRemarkEnabled
- XX: + UseConcMarkSweepGC
- XX: + UseParNewGC
- XX: + PrintGCApplicationStoppedTime
- XX: + PrintGCApplicationConcurrentTime
- XX: + PrintGCDetails
- XX: + PrintGCTimeStamps
- XX: + PrintGCDateStamps
- XX: + PrintHeapAtGC
- XX: + PrintTenuringDistribution

Я не уверен, как интерпретировать связанные журналы gc (ниже). В особенности:

  • "Куча" после GC invocations=31 (полные 3): это означает, что были 31 незначительный GCs и 3 полных GCs?

  • Что инициировало несколько последовательных строк Общего времени, на которое потоки приложения были остановлены и Время Приложения? Действительно ли возможно связать метки времени с каждой из этих строк?

Журналы GC:

Total time for which application threads were stopped: 0.0046910 seconds  
Application time: 0.7946670 seconds  
Total time for which application threads were stopped: 0.0002900 seconds  
Application time: 1.0153640 seconds  
Total time for which application threads were stopped: 0.0002780 seconds  
Application time: 1.0161890 seconds  
Total time for which application threads were stopped: 0.0002760 seconds  
Application time: 1.0145990 seconds  
Total time for which application threads were stopped: 0.0002950 seconds  
Application time: 0.9999800 seconds  
Total time for which application threads were stopped: 0.0002770 seconds  
Application time: 1.0151640 seconds
Total time for which application threads were stopped: 0.0002730 seconds
Application time: 0.9996590 seconds  
Total time for which application threads were stopped: 0.0002880 seconds  
Application time: 0.9624290 seconds  

{Heap before GC invocations=30 (full 3):  
 par new generation   total 131008K, used 130944K [0x00000000eac00000, 0x00000000f2c00000, 0x00000000f2c00000)  
  eden space 130944K, 100% used [0x00000000eac00000, 0x00000000f2be0000, 0x00000000f2be0000)  
  from space 64K,   0% used [0x00000000f2bf0000, 0x00000000f2bf0000, 0x00000000f2c00000)  
  to   space 64K,   0% used [0x00000000f2be0000, 0x00000000f2be0000, 0x00000000f2bf0000)  
 concurrent mark-sweep generation total 131072K, used 48348K [0x00000000f2c00000, 0x00000000fac00000, 0x00000000fac00000)  
 concurrent-mark-sweep perm gen total 30000K, used 19518K [0x00000000fac00000, 0x00000000fc94c000, 0x0000000100000000)  

2010-05-11T09:30:13.888+0100: 384.955: [GC 384.955: [ParNew  
Desired survivor size 32768 bytes, new threshold 0 (max 0)  
: 130944K->0K(131008K), 0.0052470 secs] 179292K->48549K(262080K), 0.0053030 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]  

Heap after GC invocations=31 (full 3):  
 par new generation   total 131008K, used 0K [0x00000000eac00000, 0x00000000f2c00000, 0x00000000f2c00000)  
  eden space 130944K,   0% used [0x00000000eac00000, 0x00000000eac00000,   0x00000000f2be0000)
  from space 64K,   0% used [0x00000000f2be0000, 0x00000000f2be0000, 0x00000000f2bf0000)  
  to   space 64K,   0% used [0x00000000f2bf0000, 0x00000000f2bf0000, 0x00000000f2c00000)  
 concurrent mark-sweep generation total 131072K, used 48549K [0x00000000f2c00000, 0x00000000fac00000, 0x00000000fac00000)  
 concurrent-mark-sweep perm gen total 30000K, used 19518K [0x00000000fac00000, 0x00000000fc94c000, 0x0000000100000000)  
}

Total time for which application threads were stopped: 0.0056410 seconds  
Application time: 0.0475220 seconds  
Total time for which application threads were stopped: 0.0001800 seconds  
Application time: 1.0174830 seconds  
Total time for which application threads were stopped: 0.0003820 seconds  
Application time: 1.0126350 seconds  
Total time for which application threads were stopped: 0.0002750 seconds  
Application time: 1.0155910 seconds
Total time for which application threads were stopped: 0.0002680 seconds
Application time: 1.0155580 seconds  
Total time for which application threads were stopped: 0.0002880 seconds  
Application time: 1.0155480 seconds  
Total time for which application threads were stopped: 0.0002970 seconds  
Application time: 0.9896810 seconds  
7
задан Joachim Sauer 11 May 2010 в 09:07
поделиться

3 ответа

эти строки без временных меток не являются событиями gc, они записывают, когда возникают точки сохранения и как долго они существуют. До 6у21 они несколько ненадежны.

2
ответ дан 7 December 2019 в 09:58
поделиться

Да, это количество минорных и мажорных коллекций вместе. Было 28 минорных GC и 3 мажорных GC.

Минорные коллекции вызывают те строки, которые вы цитируете. Если нет временных меток, я не думаю, что вы можете заставить их, кроме как модифицировать JVM. Однако я понимаю, что "время приложения" - это время, в течение которого приложение работало с момента последней незначительной коллекции (паузы), так что это может дать вам то, что вы хотите. Я полагаю, что это, по крайней мере, дельта времени с момента последнего выхода.

2
ответ дан 7 December 2019 в 09:58
поделиться

У вас будут временные метки, соответствующие каждой записи.

Пример из журнала моего сервера показывает

124951.831: [GC 1915727K->1295438K(1994752K), 0.1964641 secs]
Total time for which application threads were stopped: 0.1983187 seconds
125015.262: [GC 1909838K->1302111K(1994752K), 0.2037094 secs]
Total time for which application threads were stopped: 0.2055489 seconds

124951.831 и 125015.262 в данном случае - это количество секунд, прошедших с момента запуска JVM.

124951.831 соответствует 34 часам, 42 минутам, 31 секунде времени работы JVM.

125015.262 соответствует 34 часам, 43 минутам, 35 секундам времени работы JVM.

Вам придется соотнести это время с временем запуска сервера, и таким образом вы сможете получить временные метки.

Важна разница (125015 - 124951), которая показывает, что Minor GC запустился через 64 секунды (в моем случае).

Отсутствуют ли эти строки с временными метками в вашем журнале?

2
ответ дан 7 December 2019 в 09:58
поделиться
Другие вопросы по тегам:

Похожие вопросы: