Когда G1 GC запустит начальную метку помимо IHOP

Я установил -XX: InitiatingHeapOccupancyPercent = 70 в JDK8 (без адаптивной функции IHOP), но я обнаружил, что есть две фазы начальной отметки в начале запуска JVM, когда HeapOccupancyPercent намного меньше 70%, есть ли какой-либо другой фактор, который сработает G1 GC начальная фаза маркировки? Заранее спасибо!

Выдержка из журнала GC:

2020-01-22T03: 58: 14.227 + 0000: 3.158: [пауза GC (порог GC метаданных) (молодой) (начальная отметка), 0,1583711 сек] [Eden: 1056.0M (81920.0M) -> 0,0B (81184.0M) ) Выжившие: 0,0B-> 736,0M Куча: 1472,0M (160,0G) -> 1179,5M (160,0G)]

2020-01-22T04: 13: 07.073 + 0000: 896.004: [GC пауза (G1 Evacuation Pause) (молодой) (начальная отметка), 3.8512514 секунд] [Eden: 81184.0M (81184.0M) -> 0,0B (71904.0M ) Выжившие: 736.0M-> 10016.0M Куча: 83643.5M (160.0G) -> 11744.0M (160.0G)]

Версия JDK:

openjdk версия "1.8.0_222"

Среда выполнения OpenJDK (сборка 1.8.0_222-b10)

64-разрядная серверная виртуальная машина OpenJDK (сборка 25.222-b10, смешанный режим)

Спасибо

****** Обновление журнала сборщика мусора 2020/02/01 ************

2020-01-22T03: 58: 14.227 + 0000: 3.158: [пауза GC (порог GC метаданных) (молодой) (начальная отметка), 0,1583711 сек]

[Время параллельной обработки: 143,8 мс, работники сборщика мусора: 33]

 [GC Worker Start (ms): Min: 3158.7, Avg: 3159.4, Max: 3159.8, Diff: 1.1]

 [Ext Root Scanning (ms): Min: 0.6, Avg: 1.1, Max: 2.7, Diff: 2.1, Sum: 35.9]

 [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]

    [Processed Buffers: Min: 0, Avg: 0.1, Max: 2, Diff: 2, Sum: 4]

 [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]

 [Code Root Scanning (ms): Min: 0.0, Avg: 0.3, Max: 5.9, Diff: 5.9, Sum: 8.5]

 [Object Copy (ms): Min: 135.7, Avg: 141.1, Max: 141.5, Diff: 5.9, Sum: 4654.7]

 [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.7]

    [Termination Attempts: Min: 1, Avg: 9.1, Max: 15, Diff: 14, Sum: 301]

 [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.9]

 [GC Worker Total (ms): Min: 142.0, Avg: 142.5, Max: 143.1, Diff: 1.1, Sum: 4701.0]

 [GC Worker End (ms): Min: 3301.8, Avg: 3301.9, Max: 3301.9, Diff: 0.1]

[Исправление корневого кода: 0,1 мс]

[Очистка корневого кода: 0,0 мс]

[Устранение дедупликации строк: 0,9 мс, работники сборщика мусора: 33]

 [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]

 [Table Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.7, Diff: 0.7, Sum: 0.7]

[Очистить CT: 0,4 мс]

[Другое: 13,1 мс]

 [Choose CSet: 0.0 ms]

 [Ref Proc: 9.4 ms]

 [Ref Enq: 0.9 ms]

 [Redirty Cards: 0.6 ms]

 [Humongous Register: 0.2 ms]

 [Humongous Reclaim: 0.0 ms]

 [Free CSet: 0.1 ms]

[Иден: 1056,0M (81920,0M) -> 0,0B (81184,0M) Выжившие: 0,0B-> 736,0M Куча: 1472,0M (160,0G) -> 1179,5M (160,0G)]

[Время: пользователь = 1,77, системный = 2,98, реальный = 0,15 секунды]

2020-01-22T03: 58: 14.386 + 0000: 3.316: [GC concurrent-root-region-scan-start]

2020-01-22T03: 58: 14.458 + 0000: 3.388: [GC concurrent-mark-start]

2020-01-22T03: 58: 14.458 + 0000: 3.388: [GC concurrent-root-region-scan-end, 0,0718879 сек]

2020-01-22T03: 58: 14.485 + 0000: 3.416: [Замечание GC 2020-01-22T03: 58: 14.485 + 0000: 3.416: [Завершить маркировку, 0,0011542 секунды] 2020-01-22T03: 58: 14.486 + 0000: 3,417: [GC ref-proc, 0,0072547 с] 2020-01-22T03: 58: 14,494 + 0000: 3,424: [Выгрузка, 0,0050159 с], 0,0151448 с]

[Время: пользователь = 0,19, системное = 0,02, реальное = 0,02 секунды]

2020-01-22T03: 58: 14.485 + 0000: 3.415: [GC concurrent-mark-end, 0,0271495 сек]

2020-01-22T03: 58: 14.500 + 0000: 3.431: [Очистка GC 1259M-> 1259M (160G), 0,0033890 сек]

[Times: user = 0,06 sys = 0,00, real = 0,00 секунд]

2020-01-22T04: 13: 07.073 + 0000: 896.004: [GC пауза (G1 Evacuation Pause) (молодой) (начальная отметка), 3.8512514 секунд]

[Параллельное время: 3822,9 мс, работники сборщика мусора: 33]

 [GC Worker Start (ms): Min: 896005.5, Avg: 896006.2, Max: 896006.6, Diff: 1.1]

 [Ext Root Scanning (ms): Min: 4.3, Avg: 5.3, Max: 8.4, Diff: 4.1, Sum: 175.2]

 [Update RS (ms): Min: 0.0, Avg: 0.2, Max: 0.8, Diff: 0.8, Sum: 7.6]

    [Processed Buffers: Min: 0, Avg: 1.3, Max: 6, Diff: 6, Sum: 44]

 [Scan RS (ms): Min: 2254.9, Avg: 2266.4, Max: 2268.2, Diff: 13.3, Sum: 74790.0]

 [Code Root Scanning (ms): Min: 0.0, Avg: 0.7, Max: 10.4, Diff: 10.4, Sum: 23.8]

 [Object Copy (ms): Min: 1535.2, Avg: 1537.7, Max: 1548.1, Diff: 13.0, Sum: 50745.7]

 [Termination (ms): Min: 0.0, Avg: 11.2, Max: 13.3, Diff: 13.2, Sum: 368.0]

    [Termination Attempts: Min: 1, Avg: 2270.1, Max: 2464, Diff: 2463, Sum: 74914]

 [GC Worker Other (ms): Min: 0.0, Avg: 0.2, Max: 0.5, Diff: 0.5, Sum: 8.1]

 [GC Worker Total (ms): Min: 3821.2, Avg: 3821.8, Max: 3822.5, Diff: 1.3, Sum: 126118.4]

 [GC Worker End (ms): Min: 899827.7, Avg: 899827.9, Max: 899828.2, Diff: 0.5]

[Исправление корневого кода: 0,5 мс]

[Очистка корневого кода: 0,1 мс]

[Устранение дедупликации строк: 1,1 мс, работники сборщика мусора: 33]

 [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]

 [Table Fixup (ms): Min: 0.0, Avg: 0.1, Max: 1.0, Diff: 1.0, Sum: 1.9]

[Очистить CT: 4,7 мс]

[Другое: 21,9 мс]

 [Choose CSet: 0.0 ms]

 [Ref Proc: 8.5 ms]

 [Ref Enq: 0.9 ms]

 [Redirty Cards: 4.1 ms]

 [Humongous Register: 0.2 ms]

 [Humongous Reclaim: 0.0 ms]

 [Free CSet: 6.2 ms]

[Иден: 81184,0M (81184,0M) -> 0,0B (71904,0M) Выжившие: 736,0M-> 10016,0M Куча: 83643,5M (160,0G) -> 11744,0M (160,0G)]

[Время: пользователь = 50,77, системный = 10,33, реальный = 3,85 секунды]


jvm g1gc
person Roy Zhang    schedule 30.01.2020    source источник

Ответы (1)


arrow_upward
0
arrow_downward

Что ж, один из них очевиден, и он связан с Metaspace, вот подробнее об этом. Я имею в виду, что когда запускается полный сборщик мусора, начальная фаза - mark.

Мне известно о трех других случаях, когда запускалась фаза отметки (см. Ниже):

 1) IHOP is reached
 2) G1ReservePercent is reached
 3) a humongous allocation happens

Что происходит после фазы отметки, зависит от нескольких параметров, например, mixed GCs будет зависеть от параметра G1HeapWastePercent; но в любом случае young GC будет срабатывать после mark phase в любом случае.

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

Второй момент (из ваших комментариев): я говорил, что в целом, это причина для запуска параллельной фазы отметки, а не для вашего случая.

Но давайте посмотрим на ваш лог (я его немного отформатировал):

[GC pause (G1 Evacuation Pause) (young) (initial-mark), 3.8512514 secs]    
    [  Eden: 81184.0M(81184.0M)->0.0B(71904.0M) 
       Survivors: 736.0M->10016.0M 
       Heap: 83643.5M(160.0G)->11744.0M(160.0G)
    ]

Это показывает несколько вещей. Ваш Эдем 80GB, 70GB из которых мертвые объекты. Таким образом, Eden был уменьшен до 71904.0M, а Survivor был увеличен до 10016 M. Поскольку вы установили InitiatingHeapOccupancyPercent = 70, этого никогда не произойдет, когда Eden такой большой, это значение никогда не достигнет 70%. Подумайте об этом, вы говорите: «инициируйте этап маркировки, когда я буду 70% всей кучи в старом поколении»; но ваш eden - это 50% кучи ... Это было лишь незначительное наблюдение.

Что касается почему срабатывает - это очевидно: ваш рай был полон (81184.0M(81184.0M)). Как почему initial-mark также? Всегда срабатывает в рамках молодой коллекции.

Третий момент

Я не уверен, что понимаю, что вы имеете в виду. В журналах четко написано, что initial-mark, то есть STW event, то есть young GC.

person Eugene    schedule 31.01.2020
comment
Спасибо Евгению за твой комментарий! Что касается 3) происходит огромное распределение, у меня другое представление. Выделяется много огромных возражений (50+), но это не вызовет так много начальных отметок. - person Roy Zhang; 31.01.2020
comment
Что касается 2) G1ReservePercent достигнут, у меня тоже есть другое представление. Он находится в начале запуска JVM, максимальная используемая куча составляет 80 ГБ (общая куча составляет 160 ГБ), и в журнале gc нет переполнения пространства. - person Roy Zhang; 31.01.2020
comment
Что касается того, что я имею в виду, когда запускается полный сборщик мусора, начальная фаза - это метка. Я думаю, что это параллельный цикл меток, а не полный сборщик мусора. Мое предположение основано на причине gc [пауза GC (порог GC метаданных) (молодой) (начальная отметка), пожалуйста, дайте мне знать, если есть какие-то другие идеи, спасибо! - person Roy Zhang; 31.01.2020
comment
спасибо за ваш комментарий, относительно третьего пункта, вы упомянули, что происходит огромное распределение, которое запускает фазу отметки. Я не думаю, что это так, это моя точка зрения, надеюсь, она прояснится. Спасибо! - person Roy Zhang; 01.02.2020
comment
@RoyZhang, ты не думаешь, что это так в твоем случае, верно? это означает, что вы не думаете, что журнал, который вы представили (тот, который содержит (G1 Evacuation Pause) (young) (initial-mark)), вызван огромным распределением. правильный? - person Eugene; 01.02.2020
comment
Что касается того, почему это срабатывает - вам нужно предоставить больше журналов, которые следуют, невозможно сказать иначе, по крайней мере, для меня., Это первые 4 gc (начальная отметка, замечание, чистая, начальная отметка снова), я предоставляю в ***** обновлении от 2020/02/01 журнала GC ************, спасибо! - person Roy Zhang; 01.02.2020
comment
@RoyZhang, ты же не думаешь, что это так в твоем случае? это означает, что вы не думаете, что журнал, который вы представили (тот, который содержит (G1 Evacuation Pause) (молодой) (начальная отметка)), инициирован огромным распределением. правильно ?, @ Евгений, да, это моя точка зрения. Есть несколько огромных распределений, но это не приводит к такому количеству начальных отметок. - person Roy Zhang; 01.02.2020
comment
@RoyZhang Я отредактировал свой второй пункт, это было настолько очевидно, что мне стыдно, что я его пропустил: As to why this is triggered - this is obvious: your eden was full (81184.0M(81184.0M)). AS to why initial-mark also? It is always triggered as part of a young collection. - person Eugene; 01.02.2020
comment
@RoyZhang, ты ответил на твой вопрос? - person Eugene; 01.03.2020