Skip to main content

2026.06.04

Симптом: падения JVM после нескольких минут работы.

В логах присутствуют записи allocation stall.

allocation stall - Это предсмертное состояние JVM. GC не успевает освобождать память так же быстро, как приложение её выделяет. Когда куча заполнена на критический уровень (High Threshold), GC перестаёт принимать новые аллокации и заставляет все треды приложения ждать (stall), пока не завершится цикл сборки.

Если это длится долго - JVM выбрасывает OOM, хотя технически память ещё может быть не до конца исчерпана.

Типичные причины

1. Недостаточно памяти для ZGC

ZGC требует память под вспомогательные структуры (например, ZPage Cache). Эффективный размер кучи может быть на 10–15% меньше заданных 26 ГБ.

Решение: уменьшить -Xmx до 22–23 ГБ, освободив системе буфер.

2. Слишком быстрый аллокационный rate (особенно при потоковом импорте или массовой обработке через Kafka)

ZGC умеет держать паузы <1 мс, но пропускная способность на сборку - не бесконечная. При аллокациях >2–4 ГБ/сек начинаются сталы.

Диагностика: замерить через -Xlog:gc+stats=debug или JMX метрику ZGC%.

3. Утечка памяти внутри IDM (например, ConcurrentHashMap без эвикшена, статические кэши)

Проверьте в логах до падения: если сталы возникали периодически и нарастала базовая занятость кучи после GC (Used не опускается ниже N%) - это утечка.

4. OpenSearch + Kafka на том же стенде

 Даже 47 ГБ суммарно — тесно. Если OS или Kafka делают page cache thrashing, JVM IDM может страдать от внезапных задержек ввода-вывода, из-за чего ZGC не успевает выполнять concurrent фазы.

Рекомендация: выделить для IDM изолированные CPU ядра (taskset) и поднять приоритет GC тредов.

Как точно определить причину по логам

Искать в gc.log строки непосредственно перед OOM. Примерно так:

[ZGC] Allocation stall (creeping...)
[ZGC] Allocation stall (0.512ms) # если сталы в миллисекундах - OK
[ZGC] Allocation stall (1523ms) # если больше 200 мс - плохо

Ищем:

Allocation stall с длительностью >500 мс
Фразу Concurrent Mark aborted или OutOfMemory
Статистику перед крахом: Used: 25.8G, High: 26G, Mark start: 25.1G

Временный фикс (если нет утечки):

-Xmx22G -Xms22G -XX:+UseZGC -XX:ConcGCThreads=8 -XX:ZAllocationSpikeTolerance=5

ZAllocationSpikeTolerance=5 — разрешает ZGC чуть агрессивнее запускать сборки при всплесках.

Если утечка есть — без дампа кучи (jmap -dump:live) не обойтись.

Если нагрузки на ЦПУ нет, это важный симптом. ZGC простаивает, а память переполняется - значит, узкое место не в CPU, а в аллокациях (выделении памяти) или паузах на ввод-вывод.

Вот что обычно происходит в такой ситуации:

1. ZGC не успевает за аллокациями, но CPU не загружен

ZGC работает конкурентно. Если приложение выделяет объекты быстрее, чем ZGC успевает их чистить, то растёт занятость кучи → аллокационные сталы → OOM. CPU может быть низким, потому что ZGC не требует много ядер (обычно 1–2 на 100 ГБ кучи), а приложение сидит в ожидании памяти (stall).

2. Самая частая причина на вашем стенде: Kafka или OpenSearch забирают I/O

IDM, скорее всего, пишет/читает топики или индексирует данные через OpenSearch. Если диски медленные или перегружены: ZGC пытается сделать mmap/unmap страниц кучи (ZGC использует виртуальную память). I/O-задержки растягивают фазы сборки → аллокации обгоняют GC → сталы. При этом CPU потребляется мало, потому что время уходит на ожидание диска.

3. Ещё вариант: слишком большой -Xmx для доступной физической памяти

Если 26 ГБ + OpenSearch + Kafka дают подсистеме памяти трепетать (swapping, thrashing page cache), то ZGC может простаивать в ожидании страниц. Проверьте free -h, нет ли swap и высокого si/so в vmstat 1.

Диагностика простоем CPU:

Посмотреть, не ждёт ли IDM ввода-вывода  

pidstat -d 1 -p $(pgrep -f idm)

# Если %wait высокий (>10%) - диск тормозит

Проверить, нет ли длительных аллокационных задержек (из gc.log):

grep "Allocation stall" gc.log | tail -20

Если задержки >500 мс - подтверждение.

По выводу

pidstat -d
vmstat 1 5

будет видно, диск ли виноват.

Пример: 272–756 КБ/с записи — это очень мало, почти простаивающий диск. Значит, диск не причина.

Симптоматика:

CPU простаивает, диск не нагружен, память переполняется, а ZGC в сталлах. 

Остаются два реальных варианта:

1. Приложение просто выделяет память быстрее, чем ZGC успевает чистить

Это случается при:

Циклах с массовым созданием объектов (например, распарсили 10 ГБ JSON в HashMap)
Потоковой обработке больших сообщений из Kafka без batch-коммитов

При этом GC не нужен CPU для сборки, потому что фазы ZGC (маркировка, релокация) конкурентны, но их пропускная способность ограничена. Аллокатор просто обгоняет сборщик.

Решение:

Добавьте флаг: -XX:ConcGCThreads=12 (у вас 20 ядер, можно дать ZGC больше потоков)
Увеличьте -XX:ZCollectionInterval=30 (чтобы ZGC запускался чаще)
Но главное — профилировать аллокации в IDM. Запустите с -XX:+HeapSampling или сделайте дамп при OOM.

2. Прерывистый характер работы (burst allocation)

Если IDM долго ждёт данные, потом получает гигантский batch из Kafka, выделяет под него память мгновенно, а ZGC не успевает активироваться.

Проверка: в логах IDM есть ли паузы по 5–10 минут, потом резкий всплеск?

Решение:

-XX:SoftMaxHeapSize=20G -XX:ZUncommitDelay=5000

Это заставит ZGC держать меньше памяти и чаще собирать.

Лог GC

[2026-06-05T08:20:13.098+0300][3571566][gc] GC(50) Concurrent Mark Cycle 7234,450ms
[2026-06-05T08:20:13.951+0300][3571566][gc] GC(57) Pause Young (Normal) (G1 Evacuation Pause) 24643M->24052M(26624M) 65,993ms
[2026-06-05T08:20:14.654+0300][3571566][gc] GC(58) Pause Young (Concurrent Start) (G1 Evacuation Pause) 25172M->24704M(26624M) 70,657ms
[2026-06-05T08:20:14.654+0300][3571566][gc] GC(59) Concurrent Mark Cycle
[2026-06-05T08:20:15.450+0300][3571566][gc] GC(60) Pause Young (Normal) (G1 Evacuation Pause) (Evacuation Failure) 25824M->26083M(26624M) 95,480ms
[2026-06-05T08:20:18.009+0300][3571566][gc] GC(61) Pause Full (G1 Compaction Pause) 26083M->25206M(26624M) 2558,703ms
... (пропущено для краткости) ...
[2026-06-05T08:21:06.685+0300][3571566][gc] GC(98) Pause Young (Normal) (G1 Evacuation Pause) (Evacuation Failure) 26614M->26614M(26624M) 11,518ms

Лог чётко показывает:

Pause Young (Normal) → паузы G1
Evacuation Failure → регионы кучи переполнены, G1 не успевает их очистить
Pause Full (G1 Compaction Pause) → фатальные Full GC по 2–5 секунд

Что происходит

Куча 26 ГБ забита под завязку (26615M->26615M(26624M) — использовано 99.97%). G1 пытается копировать живые объекты во время молодых сборок, но свободных регионов нет — всё занято. Начинаются бесконечные Full GC, которые не могут ничего очистить (память падает с 26615 до 26593 МБ — копейки).

CPU простаивает, потому что приложение ждёт GC в блокировках.

Причина

G1 не справляется с объёмом живых данных. Ваше приложение держит в памяти 25+ ГБ живых объектов (кеши, сессии, невыгруженные данные). G1 для такого размера кучи даёт сбои - он не предназначен для гепа >20 ГБ с высоким процентом живущих объектов.

Немедленное решение

Переключитесь на ZGC (как и планировалось):

-XX:+UseZGC -Xmx24G -Xms24G \
-XX:ConcGCThreads=8 \
-XX:ZCollectionInterval=30 \
-XX:ZAllocationSpikeTolerance=5

ZGC умеет работать с кучей 24+ ГБ и не даёт длинных пауз.

Проверяем что флаги применились:

jcmd $(pgrep -f idm) VM.flags | grep UseZGC

Если ZGC не поможет

Значит, приложение действительно требует >25 ГБ живых данных. Тогда:

1. Увеличить -Xmx до 32 ГБ (но осторожно, останется мало памяти ОС)

2. Или найти утечку через дамп кучи:

 jmap -dump:live,format=b,file=heap.hprof <PID>

Настройки:

-Djava.net.preferIPv4Stack=true
-XX:+UseZGC
-XX:+ZGenerational
-XX:SoftMaxHeapSize=10g
-XX:ZAllocationSpikeTolerance=8
-XX:ConcGCThreads=8
-XX:ParallelGCThreads=24
-XX:+ZProactive 
-XX:+AlwaysPreTouch
-XX:+ZUncommit
-XX:ZUncommitDelay=600
-XX:+UseNUMA
-XX:MaxMetaspaceSize=512m
-XX:MetaspaceSize=256m
-XX:+PrintCommandLineFlags 
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/opt/ankey/tmp
-XX:NativeMemoryTracking=detail
-XX:+ExitOnOutOfMemoryError

-XX:SoftMaxHeapSize=10g (это для экспериментов с экономией памяти)
-XX:+ZUncommit (медленно работает на больших кучах)
-XX:+ZProactive (мешает при пиковых нагрузках)

Пока IDM работает, можете параллельно собрать диагностику "до греха" (пригодятся, если падение повторится):

1. Текущее состояние памяти ZGC

jstat -gc $(pgrep -f idm) 1s 10

   Обратите внимание на столбцы: ZHeap — занятость кучи, ZOld* / ZYoung* (если включён ZGenerational).

2. Аллокационные сталы (живой мониторинг)

tail -f /path/to/gc.log | grep --line-buffered "Allocation stall"

   Если появятся строки с задержками >100 мс — сигнал, что ZGC опять не успевает.

3. CPU-профиль (не простаивает ли?)

top -H -p $(pgrep -f idm)

При нормальной работе треды ZGC* должны потреблять 10–30% CPU. Если они близки к нулю — проблема в I/O или блокировках самого IDM.

В логе, можно обращать внимание на:

Частоту Concurrent Mark Cycle — должна быть не чаще раза в 5–10 секунд
Allocation stall — их быть не должно
High vs Used в фазе маркировки — разрыв не должен превышать 5–10%

Пока лог не пришёл: проверьте, что Xmx действительно применился:

jcmd $(pgrep -f idm) VM.flags | grep -E "Xmx|UseZGC"

Новый лог (после применения настроек)

[2026-06-05T08:31:43.472+0300][3574699][gc] Using The Z Garbage Collector
[2026-06-05T08:32:20.662+0300][3574699][gc] GC(0) Major Collection (CodeCache GC Threshold)
[2026-06-05T08:32:21.414+0300][3574699][gc] GC(0) Major Collection (CodeCache GC Threshold) 1796M(7%)->408M(2%) 0,753s
[2026-06-05T08:32:28.138+0300][3574699][gc] GC(1) Major Collection (Warmup)
[2026-06-05T08:32:28.284+0300][3574699][gc] GC(1) Major Collection (Warmup) 2666M(10%)->272M(1%) 0,146s
... (пропущено для краткости) ...
[2026-06-05T08:37:29.190+0300][3574699][gc] GC(8) Minor Collection (Allocation Rate) 11526M(43%)->19138M(72%) 4,784s
[2026-06-05T08:37:29.191+0300][3574699][gc] GC(9) Major Collection (Allocation Rate)
[2026-06-05T08:37:33.318+0300][3574699][gc] Allocation Stall (parallel-7) 217,997ms
[2026-06-05T08:37:33.318+0300][3574699][gc] Allocation Stall (pool-7-thread-1) 217,784ms
... (множество Allocation Stall) ...
[2026-06-05T08:37:40.302+0300][3574699][gc] GC(10) Minor Collection (Allocation Stall) 26624M(100%)->26624M(100%) 4,894s
[2026-06-05T08:37:40.302+0300][3574699][gc] GC(11) Minor Collection (Allocation Stall)
... (дальнейшие падения) ...
[2026-06-05T08:37:45.217+0300][3574699][gc] GC(9) Major Collection (Allocation Rate) 19138M(72%)->26624M(100%) 16,026s
[2026-06-05T08:37:45.217+0300][3574699][gc] GC(17) Major Collection (Allocation Stall)
... (бесконечные циклы сборок с 100% заполнением) ...
[2026-06-05T08:37:47.800+0300][3574699][gc] GC(29) Minor Collection (Allocation Stall) 26624M(100%)->26624M(100%) 0,034s

Диагноз абсолютно ясен

Прямое показание лога — строка 26624M(100%)->26624M(100%) повторяется раз за разом. Это значит:

Куча заполнена на 100% и ZGC не может освободить ни байта.

ZGC в генерационном режиме пытается делать Minor Collection (молодую сборку), но она не находит мёртвых объектов - всё, что в куче, живое. Через 4 секунды после старта приложение уже упёрлось в потолок.

Что это значит на практике

Вашему IDM нужно больше 26 ГБ живых данных постоянно. Это не всплеск, не утечка (пока) - это рабочий объём.

Причина почти наверняка:

Кэши IDM (сессии, результаты синхронизации, workflow)
Буферы Kafka (reactive-kafka держит огромные batch'и)
OpenSearch client (буферизует ответы)

Немедленное решение (единственное работающее)

На 47 ГБ стенда 32 ГБ для IDM — предел. Если останется <10 ГБ на Kafka+OS+OpenSearch, нужно разносить сервисы.

Если нельзя увеличить кучу — нужно резать рабочий объём

1. Уменьшить кэши IDM (найти в конфиге параметры типа cache.max.entries, session.timeout)
2. Ограничить Kafka consumer (max.poll.records=100 вместо 500)
3. Отключить ненужные модули IDM

Что смотреть дальше

После увеличения кучи (или без него) сделайте дамп:

jcmd $(pgrep -f idm) GC.heap_info