В данном топике речь пойдет о причинах, вызывающих длинные паузы сборщика мусора и о способах борьбы с ними. Рассказывать я буду о CMS (low pause), так как на данный момент это наиболее часто используемый алгоритм для приложений с большой памятью и требованием малой задержки (low latency). Описание дается в предположении, что у вас приложение крутится на боксе с большим объемом памяти и большим количеством процессоров.
Общие принципы работы GC и CMS в частности подробно описаны тут. Я лишь кратко резюмирую здесь то, что нам понадобиться для понимания данного топика:
Итак, в нашем случае мы имеем следующие моменты, когда наше приложение полностью останавливается.
Для начала нужно определить являются ли паузы в этих четырех случаях настолько большими, что портят жизнь вашему приложению. Всех лучше это смотреть на продакшен системе, так как там именно те условия, которые вам нужны. Слава богу это можно сделать абсолютно без деградации производительности, запуская JVM со следующими параметрами.
Подробно как читать логи CMS можно почитать тут. Если вы хотите, чтобы время печаталось не в относительных секундах от старта jvm, а по-человечески, можете воспользоваться парсером, который я написал на питоне. Нас же сейчас интересует только части логов о stop-the-world событиях.
Основной алгоритм минорных сборок, это копирование, таким образом чем больше живых объектов в YougGen, тем дольше работает минорная сборка. Я вижу по крайней мере три вещи на которые нужно посмотреть, когда паузы слишком большие и вас не устраивают.
a. Ваша JVM использует не подходящий алгоритм. В приведенном логе используется однопоточный алгоритм (DefNew). Я рекомендую попробовать новый многопоточный алгоритм (в логах он будет называться ParNew), который можно принудительно включить параметром -XX:+UseParNewGC. Можно еще упомянуть, что если вы видите в логах имя PSYoungGen, то это значит, что ваша JVM использует параллельный алгоритм, но старой реализации. Хотя вкупе с CMS он вроде бы не доступен.
b. Вы выделили слишком большой кусок памяти для YoungGen (в приведенном логе это циферка 235968K). Его можно уменьшить задав параметр -Xmn.
c. Вы используете слишком большой survivor space с большим разрешенным возрастом объектов, таким образом объекты копируются туда обратно и не могут запромоутиться в OldGen, давая ненужную нагрузку minor GC. Данную ситуацию можно исправить параметрами -XX:SurvivorRatio и -XX:MaxTenuringThreshold. Для более подробного анализа этого случая можно запускать JVM с параметром -XX:+PrintTenuringDistribution чтобы получить больше информации о поколениях объектов в GC логах.
В этой фазе сборщик мусора помечает все объекты, непосредственно достижимые из GC Roots. Если вы увидели, что данная фаза занимает много времени, то возможно у вас очень много ссылок ведет из локальных переменных и статических полей.
Тут можно пропробовать увеличить количество потоков (ParallelCMSThreads), участвующих в данной фазе. По умолчанию оно высчитывается как (ParallelGCThreads + 3)/4). Т.е. если ParallelGCThreads=8, то в init-mark фазе будет участвовать всего два потока, что может никакого прироста особо не дать из-за оверхеда возникающего из-за параллелизма.
Во время mark фазы работает спецальный процесс, который следит за всеми изменениями ссылок. Remark фаза нужна как раз, чтобы просмотреть все измененные ссылки.
a. Если вы видите в логах фразу «Rescan (non-parallel)», то я рекомендую включить опцию -XX:+CMSParallelRemarkEnabled, чтобы задействовать несколько потоков для этой фазы.
b. Так как очистка слабых ссылок (week reference) происходит именно в этой фазе, то посмотрите не используете ли вы их слишком много. (Например, java.util.WeakHashMap)
c. Возможно у вас очень сильно меняются ссылки. Посмотрите сколько времени проходит между inital-mark и remark. Чем меньше времени прошло между этими фазами, тем меньше будет изменено ссылок и тем быстрее свою функцию remark. Начиная с пятой java непосредственно перед remark фазой добавилась еще фаза abortable-preclean, которая по сути ничего не делает я просто висит и ждет пока не сработает минорная сборка, потом подождет еще немножко и заканчивается, запуская таким образом следующую фазу remark. Тут две причины такой логики. Первая — remark так же сканирует YoungGen и для возможности работы в мультипоточном режиме необходима минорная сборка, после которой появляется возможность эффективно разбить оставшиеся объекты в YoungGen на области для параллельной обработки. И вторая — remark довольно длительная stop-the-workd фаза и если она сработает сразу после минорной сборки, то получиться одна большая длинная пауза. Есть несколько параметров, которые позволяют управлять этим поведением CMSScheduleRemarkEdenSizeThreshold, CMSScheduleRemarkEdenPenetration, CMSMaxAbortablePrecleanTime. Я предлагаю попробовать CMSScavengeBeforeRemark который заставит сразу перед remark вызвать минорную сборку. Таким образом вы максимально сократите время между init-mark и remark и работы для remark фазы будет поменьше. Это будет особенно эффективно если паузы минорных сборок много меньше remark, что обычно и бывает.
Этот и несколько других случаев вызывающих Full GC я уже подробно описывал тут.
Вот и все что я хотел рассказать про паузы. Ах, да, пожалуйста, не используете инкрементальный CMS (-XX:+CMSIncrementalMode), если только у вас не один-два ядра. Все будет работать только медленнее.
И несколько слов о других алгоритмах.
Garbage First (G1), который должен по умолчанию появиться в Java 7 и есть возможность включить его в шестой джаве начиная с версии Java SE 6 Update 14 опциями -XX:+UnlockExperimentalVMOptions и -XX:+UseG1GC. Идея в том, чтобы разделить всю область на небольшие участки памяти, которые собирать в разные участки времени, тем самым делая очень маленькие паузы. Есть разные параметры JVM, которые позволяют задавать желаемые паузы, на основании которых память и разбивается на области. Следует заметить, что этот подход нельзя назвать универсальным, так как эффективность его работы очень сильно зависит от топологии объектов в памяти. Если вы активно используете различные кэши, на объекты которых у вас разбросаны ссылки по всему приложению, то сборка одной облости может потянуть за собой сканы большого количества других областей, что вызовет заметные паузы.
В последнее время я часто натыкаюсь на посты об Azul GC, который работает без пауз вообще, независимо от топологии объектов, размера и области памяти. Звучит очень многообещающе, но их решение долгое время было доступно только на их собственном железе (Azul's Vega systems), так как алгоритм требует специальных инструкций LVB (loaded value barrier). Хорошая новость, что наконец-то появилась возможность реализовать похожий механизм на x86-64 архитектуре интеловских процессоров. Если я бы писал ultra-low-latency приложение с нуля, то обязательно рассмотрел возможность использования данной JVM, но если ваше приложение уже находится в продакшене, и его стабильность — одно из самых главных требований, то переходить с Oracle HotSpot JVM на какую-либо другую, довольно рискованных шаг. Вспомним на сколько наткнулись проблем пользователи перейдя даже с пятой на шестую джаву.
Общие принципы работы GC и CMS в частности подробно описаны тут. Я лишь кратко резюмирую здесь то, что нам понадобиться для понимания данного топика:
- Память делится на две области YoungGen и OldGen
- В YoungGen попадают только что созданные объекты
- В OldGen попадают объекты, которые переживают несколько минорных сборок мусора
- Minor сборка мусора чистит YoungGen
- Major сборка мусора чистит OldGen
- Full GC чистить обе области
- Stop-the-world значит что ваше приложение полностью остановлено, когда работает сборка мусора
- Concurrent алгоритмы и фазы не вызывают остановку приложения, т.е. сборка мусора работает параллельно приложению
- Parallel алгоритмы и фазы это активности работающие в нескольких потоках. Они могут быть как сoncurrent, так и stop-the-world. Если явно не указано, то обычно в документации подразумевается именно stop-the-world.
- Минорные сборки мусора (minor GC) — всегда только stop-the-world
- Full GC является stop-the-world
- CMS (Concurrent Mark Sweep) имеет следующие основные фазы:
- initial mark — stop-the-world
- mark — Concurrent
- preclean — Concurrent
- remark — Stop-the-world
- sweep — Concurrent
- Поиск мертвых объектов (на которых не осталось ссылок в приложении) в традиционных сборщиках мусора осуществляется путем поиска всех живых объектов (которые достижимы по ссылкам от GC roots)
- CMS не делает дефрагментацию памяти и для управления ею использует free lists.
- GC Ergonomic (параметры задающие желаемые максимальные паузы) не работает с CMS
Итак, в нашем случае мы имеем следующие моменты, когда наше приложение полностью останавливается.
- Минорная сборка мусора
- Init-mark фаза CMS
- Remark фаза CMS
- Full GC
Для начала нужно определить являются ли паузы в этих четырех случаях настолько большими, что портят жизнь вашему приложению. Всех лучше это смотреть на продакшен системе, так как там именно те условия, которые вам нужны. Слава богу это можно сделать абсолютно без деградации производительности, запуская JVM со следующими параметрами.
-verbose:gc
-Xloggc:gc.log
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-XX:+PrintGCApplicationStoppedTime
Подробно как читать логи CMS можно почитать тут. Если вы хотите, чтобы время печаталось не в относительных секундах от старта jvm, а по-человечески, можете воспользоваться парсером, который я написал на питоне. Нас же сейчас интересует только части логов о stop-the-world событиях.
1. Тормозит минорная сборка мусора.
[GC [DefNew: 209100K->25808K(235968K), 0.0828063 secs] 209100K->202964K(1284544K), 0.0828351 secs] [Times: user=0.02 sys=0.08, real=0.08 secs]
Total time for which application threads were stopped: 0.0829205 seconds
Основной алгоритм минорных сборок, это копирование, таким образом чем больше живых объектов в YougGen, тем дольше работает минорная сборка. Я вижу по крайней мере три вещи на которые нужно посмотреть, когда паузы слишком большие и вас не устраивают.
a. Ваша JVM использует не подходящий алгоритм. В приведенном логе используется однопоточный алгоритм (DefNew). Я рекомендую попробовать новый многопоточный алгоритм (в логах он будет называться ParNew), который можно принудительно включить параметром -XX:+UseParNewGC. Можно еще упомянуть, что если вы видите в логах имя PSYoungGen, то это значит, что ваша JVM использует параллельный алгоритм, но старой реализации. Хотя вкупе с CMS он вроде бы не доступен.
b. Вы выделили слишком большой кусок памяти для YoungGen (в приведенном логе это циферка 235968K). Его можно уменьшить задав параметр -Xmn.
c. Вы используете слишком большой survivor space с большим разрешенным возрастом объектов, таким образом объекты копируются туда обратно и не могут запромоутиться в OldGen, давая ненужную нагрузку minor GC. Данную ситуацию можно исправить параметрами -XX:SurvivorRatio и -XX:MaxTenuringThreshold. Для более подробного анализа этого случая можно запускать JVM с параметром -XX:+PrintTenuringDistribution чтобы получить больше информации о поколениях объектов в GC логах.
2. Долго работает init-mark
[GC [1 CMS-initial-mark: 680168K(1048576K)] 706792K(1284544K), 0.0001161 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Total time for which application threads were stopped: 0.0002740 seconds
В этой фазе сборщик мусора помечает все объекты, непосредственно достижимые из GC Roots. Если вы увидели, что данная фаза занимает много времени, то возможно у вас очень много ссылок ведет из локальных переменных и статических полей.
Тут можно пропробовать увеличить количество потоков (ParallelCMSThreads), участвующих в данной фазе. По умолчанию оно высчитывается как (ParallelGCThreads + 3)/4). Т.е. если ParallelGCThreads=8, то в init-mark фазе будет участвовать всего два потока, что может никакого прироста особо не дать из-за оверхеда возникающего из-за параллелизма.
3. Большие паузы в фазе Remark
[GC[YG occupancy: 26624 K (235968 K)][Rescan (non-parallel) [grey object rescan, 0.0056478 secs][root rescan, 0.0001873 secs], 0.0059038 secs][weak refs processing, 0.0000090 secs] [1 CMS-remark: 750825K(1048576K)] 777449K(1284544K), 0.0059808 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
Total time for which application threads were stopped: 0.0061668 seconds
Во время mark фазы работает спецальный процесс, который следит за всеми изменениями ссылок. Remark фаза нужна как раз, чтобы просмотреть все измененные ссылки.
a. Если вы видите в логах фразу «Rescan (non-parallel)», то я рекомендую включить опцию -XX:+CMSParallelRemarkEnabled, чтобы задействовать несколько потоков для этой фазы.
b. Так как очистка слабых ссылок (week reference) происходит именно в этой фазе, то посмотрите не используете ли вы их слишком много. (Например, java.util.WeakHashMap)
c. Возможно у вас очень сильно меняются ссылки. Посмотрите сколько времени проходит между inital-mark и remark. Чем меньше времени прошло между этими фазами, тем меньше будет изменено ссылок и тем быстрее свою функцию remark. Начиная с пятой java непосредственно перед remark фазой добавилась еще фаза abortable-preclean, которая по сути ничего не делает я просто висит и ждет пока не сработает минорная сборка, потом подождет еще немножко и заканчивается, запуская таким образом следующую фазу remark. Тут две причины такой логики. Первая — remark так же сканирует YoungGen и для возможности работы в мультипоточном режиме необходима минорная сборка, после которой появляется возможность эффективно разбить оставшиеся объекты в YoungGen на области для параллельной обработки. И вторая — remark довольно длительная stop-the-workd фаза и если она сработает сразу после минорной сборки, то получиться одна большая длинная пауза. Есть несколько параметров, которые позволяют управлять этим поведением CMSScheduleRemarkEdenSizeThreshold, CMSScheduleRemarkEdenPenetration, CMSMaxAbortablePrecleanTime. Я предлагаю попробовать CMSScavengeBeforeRemark который заставит сразу перед remark вызвать минорную сборку. Таким образом вы максимально сократите время между init-mark и remark и работы для remark фазы будет поменьше. Это будет особенно эффективно если паузы минорных сборок много меньше remark, что обычно и бывает.
4. Full GC в логе
(concurrent mode failure): 798958K->74965K(1048576K), 0.0270334 secs] 1033467K->74965K(1284544K), [CMS Perm : 3022K->3022K(21248K)], 0.0270963 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
Total time for which application threads were stopped: 0.0271630 seconds
Этот и несколько других случаев вызывающих Full GC я уже подробно описывал тут.
Вот и все что я хотел рассказать про паузы. Ах, да, пожалуйста, не используете инкрементальный CMS (-XX:+CMSIncrementalMode), если только у вас не один-два ядра. Все будет работать только медленнее.
И несколько слов о других алгоритмах.
Garbage First (G1), который должен по умолчанию появиться в Java 7 и есть возможность включить его в шестой джаве начиная с версии Java SE 6 Update 14 опциями -XX:+UnlockExperimentalVMOptions и -XX:+UseG1GC. Идея в том, чтобы разделить всю область на небольшие участки памяти, которые собирать в разные участки времени, тем самым делая очень маленькие паузы. Есть разные параметры JVM, которые позволяют задавать желаемые паузы, на основании которых память и разбивается на области. Следует заметить, что этот подход нельзя назвать универсальным, так как эффективность его работы очень сильно зависит от топологии объектов в памяти. Если вы активно используете различные кэши, на объекты которых у вас разбросаны ссылки по всему приложению, то сборка одной облости может потянуть за собой сканы большого количества других областей, что вызовет заметные паузы.
В последнее время я часто натыкаюсь на посты об Azul GC, который работает без пауз вообще, независимо от топологии объектов, размера и области памяти. Звучит очень многообещающе, но их решение долгое время было доступно только на их собственном железе (Azul's Vega systems), так как алгоритм требует специальных инструкций LVB (loaded value barrier). Хорошая новость, что наконец-то появилась возможность реализовать похожий механизм на x86-64 архитектуре интеловских процессоров. Если я бы писал ultra-low-latency приложение с нуля, то обязательно рассмотрел возможность использования данной JVM, но если ваше приложение уже находится в продакшене, и его стабильность — одно из самых главных требований, то переходить с Oracle HotSpot JVM на какую-либо другую, довольно рискованных шаг. Вспомним на сколько наткнулись проблем пользователи перейдя даже с пятой на шестую джаву.
Ссылки в тему:
- Официальная документация об управлении памяти в java
- Официальная документация о настройке сборщика мусора
- Блог сотрудника Sun работавшего над GC. Здесь он подробно описывает различные аспекты работы сборки мусора. Очень рекомендую.
- FAQ по различным аспектам управления памяти JVM
- Описание альтернативной Azul GC. Так же здесь указывается на недостатки существующих решений и объясняется, чем они вызваны.
