Гость
Войти | Профиль | Очистить
Целевая тема:
Создать новую тему:
Автор:
Действия ...
Форумы / Java [игнор отключен] [закрыт для гостей] / Длинные сборки мусора (50 сек) при работе приложения. / 8 сообщений из 8, страница 1 из 1
22.07.2013, 15:09:05
    #38339178
kZ25
kZ25
Участник
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Длинные сборки мусора (50 сек) при работе приложения.
Здравствуйте,

Периодически приложение останавливается на длительный период - 50 и более секунд. Вывод логов от сборщика мусора показывает что проблемы именно в нем. Загрузка процессора не возрастает на 100 процентов в течении этой минуты. Что же сборщик мусора может так долго делать и как можно от этого избавиться?

Настройки Ява:
JAVA_OPTS="-Xms5g -Xmx5g -XX:MaxPermSize=512m -Djava.net.preferIPv4Stack=true -Dorg.jboss.resolver.warning=true"
JAVA_OPTS="$JAVA_OPTS -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000"
JAVA_OPTS="$JAVA_OPTS -Djboss.modules.system.pkgs=$JBOSS_MODULES_SYSTEM_PKGS -Djava.awt.headless=true"
JAVA_OPTS="$JAVA_OPTS -Djboss.server.default.config=standalone.xml"

JAVA_OPTS="$JAVA_OPTS -XX:NewRatio=10"
JAVA_OPTS="$JAVA_OPTS -XX:SurvivorRatio=8"
JAVA_OPTS="$JAVA_OPTS -XX:MaxTenuringThreshold=2"
JAVA_OPTS="$JAVA_OPTS -XX:+UseConcMarkSweepGC"
JAVA_OPTS="$JAVA_OPTS -XX:+UseParNewGC"
JAVA_OPTS="$JAVA_OPTS -XX:+DisableExplicitGC"
JAVA_OPTS="$JAVA_OPTS -XX:CMSInitiatingOccupancyFraction=50"
JAVA_OPTS="$JAVA_OPTS -verbose:gc"
JAVA_OPTS="$JAVA_OPTS -Xdebug"
JAVA_OPTS="$JAVA_OPTS -XX:+PrintGCDetails"
JAVA_OPTS="$JAVA_OPTS -XX:+PrintGCTimeStamps"
JAVA_OPTS="$JAVA_OPTS -XX:+PrintGCDateStamps"
JAVA_OPTS="$JAVA_OPTS -XX:+PrintClassHistogram"
JAVA_OPTS="$JAVA_OPTS -XX:+PrintTenuringDistribution"
JAVA_OPTS="$JAVA_OPTS -XX:+PrintGCApplicationStoppedTime"
JAVA_OPTS="$JAVA_OPTS -XX:+PrintGCApplicationConcurrentTime"
JAVA_OPTS="$JAVA_OPTS -XX:+PrintHeapAtGC"
JAVA_OPTS="$JAVA_OPTS -Xloggc:$JBOSS_HOME/standalone/log/gc.log"
JAVA_OPTS="$JAVA_OPTS -XX:+HeapDumpOnOutOfMemoryError"
JAVA_OPTS="$JAVA_OPTS -XX:HeapDumpPath=$JBOSS_HOME/standalone/log/heapdump.hprof"


Лог сборщика мусора:


Total time for which application threads were stopped: 0.1230460 seconds
Application time: 0.3446200 seconds
{Heap before GC invocations=29313 (full 186):
par new generation total 428992K, used 428992K [0x00000006a0000000, 0x00000006bd170000, 0x00000006bd170000)
eden space 381376K, 100% used [0x00000006a0000000, 0x00000006b7470000, 0x00000006b7470000)
from space 47616K, 100% used [0x00000006ba2f0000, 0x00000006bd170000, 0x00000006bd170000)
to space 47616K, 0% used [0x00000006b7470000, 0x00000006b7470000, 0x00000006ba2f0000)
concurrent mark-sweep generation total 4766272K, used 1174556K [0x00000006bd170000, 0x00000007e0000000, 0x00000007e0000000)
concurrent-mark-sweep perm gen total 172572K, used 103487K [0x00000007e0000000, 0x00000007ea887000, 0x0000000800000000)
2013-07-20T10:44:38.572+0000: 74754.739: [GC 74754.739: [ParNew
Desired survivor size 24379392 bytes, new threshold 2 (max 2)
- age 1: 13250584 bytes, 13250584 total
: 428992K->42894K(428992K), 56.8517130 secs] 1603548K->1253509K(5195264K), 56.8519660 secs] [Times: user=238.13 sys=0.00, real=56.86 secs ]
Heap after GC invocations=29314 (full 186):
par new generation total 428992K, used 42894K [0x00000006a0000000, 0x00000006bd170000, 0x00000006bd170000)
eden space 381376K, 0% used [0x00000006a0000000, 0x00000006a0000000, 0x00000006b7470000)
from space 47616K, 90% used [0x00000006b7470000, 0x00000006b9e539d8, 0x00000006ba2f0000)
to space 47616K, 0% used [0x00000006ba2f0000, 0x00000006ba2f0000, 0x00000006bd170000)
concurrent mark-sweep generation total 4766272K, used 1210614K [0x00000006bd170000, 0x00000007e0000000, 0x00000007e0000000)
concurrent-mark-sweep perm gen total 172572K, used 103487K [0x00000007e0000000, 0x00000007ea887000, 0x0000000800000000)
}
Total time for which application threads were stopped: 56.8532560 seconds
Application time: 0.0166630 seconds
Total time for which application threads were stopped: 0.0011880 seconds
Application time: 0.0821200 seconds
Total time for which application threads were stopped: 0.0011150 seconds

Спасибо.
...
Рейтинг: 0 / 0
| Ответить | Цитировать | Написать  
22.07.2013, 15:22:14
    #38339216
Blazkowicz
Blazkowicz
Участник
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Длинные сборки мусора (50 сек) при работе приложения.
Почему NewRatio такой? Пробовали делать меньше, чтобы увеличить Eden?
...
Рейтинг: 0 / 0
| Ответить | Цитировать | Написать  
22.07.2013, 15:46:19
    #38339266
ivanra
ivanra
Гость
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Длинные сборки мусора (50 сек) при работе приложения.
Согласен. Я бы тоже 10:1 не делал, хотя бы 3:1 (-XX:NewRatio=3), а так скорее всего для короткоживущих объектов места маловато и они дружно в Old Gen переезжают.
...
Рейтинг: 0 / 0
| Ответить | Цитировать | Написать  
22.07.2013, 16:49:29
    #38339367
kZ25
kZ25
Участник
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Длинные сборки мусора (50 сек) при работе приложения.
Спасибо за ответы, попробую увеличить Eden в два раза.
А как, в целом, такую задержку можно обяснить? Просто сборкой мусора в Old Gen?
Максимум Old Gen был заполнен на 2 GB из 4. Неужто перебор 2 гигабайтов в памяти может занимать 50 секунд?
...
Рейтинг: 0 / 0
| Ответить | Цитировать | Написать  
22.07.2013, 17:02:11
    #38339402
Blazkowicz
Blazkowicz
Участник
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Длинные сборки мусора (50 сек) при работе приложения.
kZ25Спасибо за ответы, попробую увеличить Eden в два раза.
А как, в целом, такую задержку можно обяснить? Просто сборкой мусора в Old Gen?
Максимум Old Gen был заполнен на 2 GB из 4. Неужто перебор 2 гигабайтов в памяти может занимать 50 секунд?
Нет. OldGen aka Tenured здесь, скорее всего, не при чем.

Вообще видно что Eden заполнен полностью и очистился полностью. Что наводит на мысль что его не хватало.

ParNew работает исключительно для молодого поколения. Но он там ещё каким-то образом синхронизируется в CMS из-за чего может проваливаться в stop-the-world.
Нужно почитать мануалы и статьи и разобраться как работает ParNew. Для него есть отдельные ключи типа того же MaxTenuringThreshold. Нужно разобраться что они меняют.

Но, начать стоит с увеличения Young и далее уже действовать в зависимости от результата.
...
Рейтинг: 0 / 0
| Ответить | Цитировать | Написать  
22.07.2013, 18:12:49
    #38339537
ivanra
ivanra
Гость
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Длинные сборки мусора (50 сек) при работе приложения.
kZ25Спасибо за ответы, попробую увеличить Eden в два раза.
А как, в целом, такую задержку можно обяснить? Просто сборкой мусора в Old Gen?
Максимум Old Gen был заполнен на 2 GB из 4. Неужто перебор 2 гигабайтов в памяти может занимать 50 секунд?
По идее не должен, но тут уже может быть и железо, и система. Поскольку процессор во время сборки не нагружался, можно предположить своп (надо смотреть что происходило с диском).
Но в любом случае NewRatio надо уменьшать. По умолчанию для серверов это 2. А сейчас такая картина:
- под кучу выделено 5гб
- 10/11 из этих 5гб выделено под oldgen, и из них используется максимум 2, остальные 2 с лишним гб простаивают
- 1/11 из этих 5гб (~500мб) используется для eden и survivor в соотношении 8:1 (SurvivorRatio), и это то место, где сборка самая дешевая

А можно было бы:
NewRatio=2, в этоим случае под old выделяется 2/3 от 5 ~ 3,3гб, остальное (1,6гб) - под место, где сборка дешевая и быстрая, поэтому все короткоживущие объекты должны умереть здесь

Кроме указанных коэффициентов можно еще порекомендовать инкрементальную сборку, она должна уменьшать паузы full gc (но только если у вас несколько ядер!):
-XX:+CMSIncrementalMode -XX:+CMSIncrementalPacing
...
Рейтинг: 0 / 0
| Ответить | Цитировать | Написать  
22.07.2013, 21:54:47
    #38339752
ivanra
ivanra
Гость
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Длинные сборки мусора (50 сек) при работе приложения.
Про CMSIncrementalMode напутал (вот что значит конец рабочего дня! скопировал установки с тестовой конфигурации). Он как раз разработан для машин где ядер недостаточно, чтобы поток со сборщиком full gc не останавливал надолго все остальные потоки. так что ставьте
-XX:+CMSIncrementalMode если ядер мало
-XX:-CMSIncrementalMode если ядер много
...
Рейтинг: 0 / 0
| Ответить | Цитировать | Написать  
12.08.2013, 16:33:32
    #38363512
kZ25
kZ25
Участник
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Длинные сборки мусора (50 сек) при работе приложения.
Всем спасибо.
Проблема решиласть уменшением XX:NewRatio до 3. Все задержки теперь меньше секунды
...
Рейтинг: 0 / 0
| Ответить | Цитировать | Написать  
Форумы / Java [игнор отключен] [закрыт для гостей] / Длинные сборки мусора (50 сек) при работе приложения. / 8 сообщений из 8, страница 1 из 1
Найденые пользователи ...
Разблокировать пользователей ...
Читали тему (0):
Читали форум (0):
Пользователи онлайн (0):
Польз. соглашение  
Полит. конфиден.  
созд. / загр.: 535ms
Закрыть
start [/forum/topic.php?fid=59&mobile=1&tid=2128827]:
 0ms
get settings:
 17ms
get forum list:
 24ms
check forum access:
 7ms
check topic access:
 7ms
track hit:
 51ms
get topic data:
 17ms
get forum data:
 5ms
get page messages:
 67ms
get tp. blocked users:
 2ms
others: 338ms
total:  535ms
x
x
Закрыть


Просмотр
0 / 0
Close
Debug Console [Select Text]