Ведение журнала Java 11 GC

#java #garbage-collection

Вопрос:

У меня есть одно приложение, работающее на Java 11 с включенным ведением журнала gc. Я вижу следующие строки, напечатанные в журнале GC каждые 5/6 секунды. означает ли это, что GC запускается каждые 5 секунд ?

 [2020-07-14T10:01:14.789-0400][gc,start      ] GC(353) Pause Young (Normal) (G1 Evacuation Pause)
[2020-07-14T10:01:14.789-0400][gc,task       ] GC(353) Using 8 workers of 8 for evacuation
[2020-07-14T10:01:14.790-0400][gc,phases     ] GC(353)   Pre Evacuate Collection Set: 0.0ms
[2020-07-14T10:01:14.790-0400][gc,phases     ] GC(353)   Evacuate Collection Set: 0.6ms
[2020-07-14T10:01:14.790-0400][gc,phases     ] GC(353)   Post Evacuate Collection Set: 0.5ms
[2020-07-14T10:01:14.790-0400][gc,phases     ] GC(353)   Other: 0.3ms
[2020-07-14T10:01:14.790-0400][gc,heap       ] GC(353) Eden regions: 147->0(147)
[2020-07-14T10:01:14.790-0400][gc,heap       ] GC(353) Survivor regions: 1->1(19)
[2020-07-14T10:01:14.790-0400][gc,heap       ] GC(353) Old regions: 16->16
[2020-07-14T10:01:14.790-0400][gc,heap       ] GC(353) Humongous regions: 1->1
[2020-07-14T10:01:14.790-0400][gc,metaspace  ] GC(353) Metaspace: 43129K->43129K(1089536K)
[2020-07-14T10:01:14.791-0400][gc            ] GC(353) Pause Young (Normal) (G1 Evacuation Pause) 163M->16M(248M) 1.689ms
[2020-07-14T10:01:14.791-0400][gc,cpu        ] GC(353) User=0.00s Sys=0.01s Real=0.01s
[2020-07-14T10:01:20.411-0400][gc,start      ] GC(354) Pause Young (Normal) (G1 Evacuation Pause)
[2020-07-14T10:01:20.411-0400][gc,task       ] GC(354) Using 8 workers of 8 for evacuation
[2020-07-14T10:01:20.412-0400][gc,phases     ] GC(354)   Pre Evacuate Collection Set: 0.0ms
[2020-07-14T10:01:20.412-0400][gc,phases     ] GC(354)   Evacuate Collection Set: 0.6ms
[2020-07-14T10:01:20.412-0400][gc,phases     ] GC(354)   Post Evacuate Collection Set: 0.5ms
[2020-07-14T10:01:20.412-0400][gc,phases     ] GC(354)   Other: 0.3ms
[2020-07-14T10:01:20.412-0400][gc,heap       ] GC(354) Eden regions: 147->0(147)
[2020-07-14T10:01:20.412-0400][gc,heap       ] GC(354) Survivor regions: 1->1(19)
[2020-07-14T10:01:20.412-0400][gc,heap       ] GC(354) Old regions: 16->16
[2020-07-14T10:01:20.412-0400][gc,heap       ] GC(354) Humongous regions: 1->1
[2020-07-14T10:01:20.412-0400][gc,metaspace  ] GC(354) Metaspace: 43129K->43129K(1089536K)
[2020-07-14T10:01:20.412-0400][gc            ] GC(354) Pause Young (Normal) (G1 Evacuation Pause) 163M->16M(248M) 1.536ms
[2020-07-14T10:01:20.412-0400][gc,cpu        ] GC(354) User=0.00s Sys=0.00s Real=0.00s
[2020-07-14T10:01:25.939-0400][gc,start      ] GC(355) Pause Young (Normal) (G1 Evacuation Pause)
[2020-07-14T10:01:25.939-0400][gc,task       ] GC(355) Using 8 workers of 8 for evacuation
[2020-07-14T10:01:25.940-0400][gc,phases     ] GC(355)   Pre Evacuate Collection Set: 0.0ms
[2020-07-14T10:01:25.940-0400][gc,phases     ] GC(355)   Evacuate Collection Set: 0.6ms
[2020-07-14T10:01:25.940-0400][gc,phases     ] GC(355)   Post Evacuate Collection Set: 0.5ms
[2020-07-14T10:01:25.940-0400][gc,phases     ] GC(355)   Other: 0.3ms
[2020-07-14T10:01:25.940-0400][gc,heap       ] GC(355) Eden regions: 147->0(147)
[2020-07-14T10:01:25.940-0400][gc,heap       ] GC(355) Survivor regions: 1->1(19)
[2020-07-14T10:01:25.940-0400][gc,heap       ] GC(355) Old regions: 16->16
[2020-07-14T10:01:25.940-0400][gc,heap       ] GC(355) Humongous regions: 1->1
[2020-07-14T10:01:25.940-0400][gc,metaspace  ] GC(355) Metaspace: 43129K->43129K(1089536K)
[2020-07-14T10:01:25.940-0400][gc            ] GC(355) Pause Young (Normal) (G1 Evacuation Pause) 163M->16M(248M) 1.537ms
[2020-07-14T10:01:25.940-0400][gc,cpu        ] GC(355) User=0.01s Sys=0.00s Real=0.01s
 

Комментарии:

1. ДА. И поскольку это Java 11, GC по умолчанию-G1 GC. Это не является остановкой мирового GC и делает это только на небольших участках кучи.

2. @Nishit G1 — это Остановить Мир GC

3. @AlexeyRagozin Приношу свои извинения. Ты прав.

Ответ №1:

Да, это так. Это также означает, что ваше приложение остановлено примерно 1.5 ms на время работы GC. В частности, он очищает регионы молодого поколения. Это нормально, не о чем беспокоиться.

Комментарии:

1. Означает ли это, что GC запускается каждые 5/6 секунд независимо от использования памяти приложением ?

2. @dsingh что ты имеешь в виду независимо? Ваши молодые регионы заполняются, поэтому запускается GC

3. Я увеличил размер кучи с 256 МБ до 512 МБ, используя-Xmx512m наблюдал за файлом журнала в течение нескольких минут. я вижу строки журнала, напечатанные в журнале ровно каждые 5 или 6 минут. очень маловероятно, что области памяти заполняются ровно каждые 5 или 6 минут. Извините, я из фона C и недавно начал управлять приложением java. не имею большого представления о java GC.

4. Если GC запускается, это означает, что ваше приложение выделяет материалы, и регионы заполняются, это не имеет ничего общего с подобием; это факт, подтвержденный наличием таких записей в журналах. И -Xmx увеличивает максимальную память, к вашему сведению. Для повторной итерации это то, как GC работает в мире JVM — это нормально.