Подтвердить что ты не робот

GC Tuning - предотвращение полного GC

Я пытаюсь избежать Full GC (из примера gc.log ниже) запуск приложения Grails в Tomcat в производстве. Любые предложения о том, как лучше настроить GC?

14359.317: [Полный GC 14359.317: [CMS: 3453285K- > 3099828K (4194304K), 13.1778420 secs] 4506618K- > 3099828K (6081792K), [CMS Perm: 261951K- > 181304K (264372K)] icms_dc = 0, 13.1786310 сек]] [Times: user = 13.15 sys = 0.04, real = 13.18 secs]

Мои параметры VM следующие:
-Xms = 6G
-Xmx = 6G
-XX: MaxPermSize = 1G
-XX: NewSize = 2G
-XX: MaxTenuringThreshold = 8
-XX: SurvivorRatio = 7
-XX: + UseConcMarkSweepGC
-XX: + CMSClassUnloadingEnabled
-XX: + CMSPermGenSweepingEnabled
-XX: + CMSIncrementalMode
-XX: CMSInitiatingOccupancyFraction = 60
-XX: + UseCMSInitiatingOccupancyOnly
-XX: + HeapDumpOnOutOfMemoryError
-XX: + PrintGCDetails
-XX: + PrintGCTimeStamps
-XX: + PrintTenuringDistribution
-Dsun.reflect.inflationThreshold = 0 

    14169.764: [GC 14169.764: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   15584312 bytes,   15584312 total
    - age   2:   20053704 bytes,   35638016 total
    - age   3:   13624872 bytes,   49262888 total
    - age   4:   14469608 bytes,   63732496 total
    - age   5:   10553288 bytes,   74285784 total
    - age   6:   11797648 bytes,   86083432 total
    - age   7:   12591328 bytes,   98674760 total
    : 1826161K->130133K(1887488K), 0.1726640 secs] 5216326K->3537160K(6081792K) icms_dc=0 , 0.1733010 secs] [Times: user=0.66 sys=0.03, real=0.17 secs] 
    14218.712: [GC 14218.712: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   25898512 bytes,   25898512 total
    - age   2:   10308160 bytes,   36206672 total
    - age   3:   16927792 bytes,   53134464 total
    - age   4:   13493608 bytes,   66628072 total
    - age   5:   14301832 bytes,   80929904 total
    - age   6:   10448408 bytes,   91378312 total
    - age   7:   11724056 bytes,  103102368 total
    - age   8:   12299528 bytes,  115401896 total
    : 1807957K->147911K(1887488K), 0.1664510 secs] 5214984K->3554938K(6081792K) icms_dc=0 , 0.1671290 secs] [Times: user=0.61 sys=0.00, real=0.17 secs] 
    14251.429: [GC 14251.430: [ParNew
    Desired survivor size 107347968 bytes, new threshold 7 (max 8)
    - age   1:   25749296 bytes,   25749296 total
    - age   2:   20111888 bytes,   45861184 total
    - age   3:    7580776 bytes,   53441960 total
    - age   4:   16819072 bytes,   70261032 total
    - age   5:   13209968 bytes,   83471000 total
    - age   6:   14088856 bytes,   97559856 total
    - age   7:   10371160 bytes,  107931016 total
    - age   8:   11426712 bytes,  119357728 total
    : 1825735K->155304K(1887488K), 0.1888880 secs] 5232762K->3574222K(6081792K) icms_dc=0 , 0.1895340 secs] [Times: user=0.74 sys=0.06, real=0.19 secs] 
    14291.342: [GC 14291.343: [ParNew
    Desired survivor size 107347968 bytes, new threshold 7 (max 8)
    - age   1:   25786480 bytes,   25786480 total
    - age   2:   21991848 bytes,   47778328 total
    - age   3:   16650000 bytes,   64428328 total
    - age   4:    7387368 bytes,   71815696 total
    - age   5:   16777584 bytes,   88593280 total
    - age   6:   13098856 bytes,  101692136 total
    - age   7:   14029704 bytes,  115721840 total
    : 1833128K->151603K(1887488K), 0.1941170 secs] 5252046K->3591384K(6081792K) icms_dc=0 , 0.1947390 secs] [Times: user=0.82 sys=0.04, real=0.20 secs] 
    14334.142: [GC 14334.143: [ParNew
    Desired survivor size 107347968 bytes, new threshold 6 (max 8)
    - age   1:   31541800 bytes,   31541800 total
    - age   2:   20826888 bytes,   52368688 total
    - age   3:   19155264 bytes,   71523952 total
    - age   4:   16422240 bytes,   87946192 total
    - age   5:    7235616 bytes,   95181808 total
    - age   6:   16549000 bytes,  111730808 total
    - age   7:   13026064 bytes,  124756872 total
    : 1829427K->167467K(1887488K), 0.1890190 secs] 5269208K->3620753K(6081792K) icms_dc=0 , 0.1896630 secs] [Times: user=0.80 sys=0.03, real=0.19 secs] 
    14359.317: [Full GC 14359.317: [CMS: 3453285K->3099828K(4194304K), 13.1778420 secs] 4506618K->3099828K(6081792K), [CMS Perm : 261951K->181304K(264372K)] icms_dc=0 , 13.1786310 secs] [Times: user=13.15 sys=0.04, real=13.18 secs]
    14373.287: [GC [1 CMS-initial-mark: 3099828K(4194304K)] 3100094K(6081792K), 0.0107380 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 
    14373.298: [CMS-concurrent-mark-start]
    14472.579: [GC 14472.579: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   42849392 bytes,   42849392 total
    : 1677824K->86719K(1887488K), 0.1056680 secs] 4777652K->3186547K(6081792K) icms_dc=0 , 0.1063280 secs] [Times: user=0.61 sys=0.00, real=0.11 secs] 
    14506.980: [GC 14506.980: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   42002904 bytes,   42002904 total
    - age   2:   35733928 bytes,   77736832 total
    : 1764543K->96136K(1887488K), 0.0982790 secs] 4864371K->3195964K(6081792K) icms_dc=0 , 0.0988960 secs] [Times: user=0.53 sys=0.01, real=0.10 secs] 
    14544.285: [GC 14544.286: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   26159736 bytes,   26159736 total
    - age   2:   37842840 bytes,   64002576 total
    - age   3:   33192784 bytes,   97195360 total
    : 1773960K->130799K(1887488K), 0.1208590 secs] 4873788K->3230628K(6081792K) icms_dc=0 , 0.1215900 secs] [Times: user=0.59 sys=0.02, real=0.13 secs] 
    14589.266: [GC 14589.266: [ParNew
    Desired survivor size 107347968 bytes, new threshold 4 (max 8)
    - age   1:   28010360 bytes,   28010360 total
    - age   2:   21136704 bytes,   49147064 total
    - age   3:   35081376 bytes,   84228440 total
    - age   4:   32468056 bytes,  116696496 total
    : 1808623K->148284K(1887488K), 0.1423150 secs] 4908452K->3248112K(6081792K) icms_dc=0 , 0.1429440 secs] [Times: user=0.70 sys=0.02, real=0.14 secs] 
    14630.947: [GC 14630.947: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   28248240 bytes,   28248240 total
    - age   2:   20712320 bytes,   48960560 total
    - age   3:   18217168 bytes,   67177728 total
    - age   4:   34834832 bytes,  102012560 total
    : 1826108K->140347K(1887488K), 0.1784680 secs] 4925936K->3275469K(6081792K) icms_dc=0 , 0.1790920 secs] [Times: user=0.98 sys=0.03, real=0.18 secs] 
    14664.779: [GC 14664.779: [ParNew
    Desired survivor size 107347968 bytes, new threshold 5 (max 8)
    - age   1:   25841000 bytes,   25841000 total
    - age   2:   22264960 bytes,   48105960 total
    - age   3:   17730104 bytes,   65836064 total
    - age   4:   17988048 bytes,   83824112 total
    - age   5:   34739384 bytes,  118563496 total
    : 1818171K->147603K(1887488K), 0.1714160 secs] 4953293K->3282725K(6081792K) icms_dc=0 , 0.1720530 secs] [Times: user=0.82 sys=0.11, real=0.17 secs] 
    14702.488: [GC 14702.489: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   26887368 bytes,   26887368 total
    - age   2:   21403352 bytes,   48290720 total
    - age   3:   18732224 bytes,   67022944 total
    - age   4:   17640576 bytes,   84663520 total
    - age   5:   17942952 bytes,  102606472 total
    : 1825427K->142695K(1887488K), 0.2118320 secs] 4960549K->3312168K(6081792K) icms_dc=0 , 0.2124630 secs] [Times: user=1.13 sys=0.14, real=0.21 secs]

Стратегия, на которую я стремилась: Я хочу ограничить минимум, что получает Tenured, я обслуживаю запросы и ожидаю, что за пределами определенного количества общих объектов, все другие объекты полезны только для этого запроса. Поэтому, используя большой NewSize и увеличенный TenuringThreshold, и надеялся, что ни один из этих одиночных сервисов не будет закрыт.

Для поддержки моей стратегии необходимо следующее:
-Xms = 6G
-Xmx = 6G
-XX: NewSize = 2G//большое пространство, так что ParNew не возникает часто и позволяет истечению срока для объектов

-XX: MaxTenuringThreshold = 8//чтобы ограничить владение еще одним
-XX: SurvivorRatio = 7//на основе примеров -XX: CMSInitiatingOccupancyFraction = 60
//для предотвращения полного GC, вызванного несогласованностью продвижения,

-XX: + UseCMSInitiatingOccupancyOnly
//идти с приведенным выше на примере

MaxPermSize = 1G и "-Dsun.reflect.inflationThreshold = 0" связаны с другой проблемой, которую я предпочитаю хранить отдельно.

"- XX: + CMSClassUnloadingEnabled" и "-XX: + CMSPermGenSweepingEnabled" есть из-за граалей, которые сильно полагаются и дополнительные классы для закрытия и рефлексии

-XX: + CMSIncrementalMode - эксперимент, который не приносит большого успеха

4b9b3361

ОТВЕТЫ

Ответ 1

Опубликованный фрагмент журнала показывает, что у вас есть значительное количество объектов, которые живут в течение > 320 с (приблизительно 40 с на юную коллекцию и объекты выживают через 8 коллекций до продвижения по службе). Оставшиеся объекты затем истекают кровью, и в итоге вы попадаете в неожиданно полный gc, который на самом деле не собирает очень много.

3453285K->3099828K(4194304K)

то есть. у вас есть 4G, который составляет ~ 82% (3453285/4194304), когда он срабатывает и составляет ~ 74% после 13 долгих секунд.

Это означает, что потребовалось 13 с, чтобы собрать общую сумму ~ 350 М, что в контексте кучи 6G не много.

Это в основном означает, что ваша куча недостаточно велика или, возможно, более вероятно, что у вас есть утечка памяти. Подобная утечка является ужасной вещью для CMS, потому что одновременная коллективная коллекция представляет собой некомпактное событие, которое означает, что tenured представляет собой набор бесплатных списков, что означает, что фрагментация может быть большой проблемой для CMS, что означает, что ваше использование tenured становится все более неэффективным, означает, что существует повышенная вероятность событий неудачи продвижения (хотя, если это было такое событие, тогда я ожидал увидеть сообщение в журнале, говорящее об этом), потому что он хочет рекламировать (или считает, что ему нужно продвигать) X MB в качестве но он не имеет (смежного) свободного спискa >= X МБ. Это вызывает неожиданную коллекцию, которая не является удаленным одновременным событием STW. Если у вас на самом деле есть немного, чтобы собрать (как и вы), то нет ничего удивительного в том, что вы сидите, сжимая большие пальцы.

Некоторые общие указатели, в значительной степени повторяющие то, что сказал Владимир Ситнитов...

  • Использование iCMS в многоядерном ящике не имеет смысла (если у вас нет большого количества JVM или других процессов, работающих на этом поле, так что JVM действительно не хватает ЦП), поэтому удалите этот переключатель
  • ваши молодые коллекции излишне длинны из-за влияния копирования относительно значительного количества памяти между пространствами оставшихся в живых в каждой коллекции, 150-200 мс - действительно довольно массивная коллекция ParNew
    • правильный ответ на проблему молодого поколения зависит от того, каково поведение распределения (напр., возможно, вам было бы лучше начать работу на ранней стадии и уменьшить влияние фрагментации на коллективные коллекции или, возможно, вам было бы лучше иметь более массивный новый ген и сокращение частоты коллекций молодых поколений, так что меньше объектов продвигается так, что минимальное кровотечение влагалище).

Некоторые вопросы...

  • В конечном итоге он переходит на OoM или восстанавливается?
  • - приложение в устойчивом состоянии (при условии согласованной загрузки в какой-то момент, помимо запуска) во время этого отрывка в журнале или в стрессе?

Ответ 2

Я обслуживаю запросы и ожидаю, что за пределами определенного количества общих объектов любые другие объекты полезны только для запроса. То, что теория, но любые типы кэшей, может легко аннулировать это предположение и создать объекты, которые живут за пределами запроса.

Как отмечали другие, ни ваше огромное молодое поколение, ни расширенное владение, похоже, не работают.

Вы должны профилировать свое приложение и анализировать возрастное распределение объектов. Я уверен, что Grails кэширует всевозможные вещи, выходящие за рамки запроса, и что течет в старый ген.

То, что вы пытаетесь по существу, - пожертвовать временем паузы молодого поколения (для молодого поколения 2 ГБ), чтобы отложить неизбежное - коллекцию старого поколения размером 6 ГБ. Это не совсем хороший компромисс, который вы там делаете.

Вместо этого вы, вероятно, должны стремиться к более ранним временам пауз и времени CMS, чтобы сжечь больше времени процессора: больше потоков GC контрепречной фазы (не помню вариант для этого), более высокий GCTimeRatio, a MaxGCPauseMillis > MaxGCMinorPauseMillis, чтобы оказать давление на второстепенные коллекции и позволить им выполнить свои задачи паузы вместо того, чтобы изменять размер, чтобы соответствовать максимальному лимиту сбора.

Чтобы сделать основные GC менее болезненными, вы можете прочитать это: http://blog.ragozin.info/2012/03/secret-hotspot-option-improving-gc.html (этот патч должен быть в j7u4). CMSParallelRemarkEnabled также должен быть включен, не уверен, что это значение по умолчанию.

Альтернатива: используйте G1GC

Лично у меня есть некоторые ужасные впечатления от того, как G1GC работает в угол из-за очень больших LRU-подобных нагрузок, а затем возвращается к большому стоп-стоп-коллективу гораздо чаще, чем CMS, испытывает сбои в параллельном режиме для такая же рабочая нагрузка.

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

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

Изменить: Oracle улучшила эвристику G1GC и некоторые узкие места, так как я написал этот ответ. Это определенно стоит попробовать сейчас.

Другая альтернатива: Пропускной коллектор

Как вы уже используете параллельный сборщик для 2 ГБ молодого поколения и уходите с паузами в 200 мс... почему бы не попробовать параллельный старый коллекционер gen на своей куче 6G? Вероятно, это займет меньше, чем 10s + крупных коллекций, которые вы видите с CMS. Всякий раз, когда CMS запускается в один из своих режимов отказа, он делает однопоточную, стоп-мирную коллекцию.

Ответ 3

Пожалуйста, опишите, сколько процессоров можно использовать для Tomcat? 4?

Какую версию java вы используете? ( > 1,6,0u23?)

0). Из полного выхода GC это определенно похоже на то, что вы нажимаете ограничение памяти: даже после полного gc есть еще 3099828K используемой памяти (из 4194304K). Невозможно предотвратить полный GC, когда вы потеряли память.

Ожидается ли рабочий набор 3.1Gb для вашего приложения? Это 3.1Gb памяти без мусора!

Если это ожидается, пришло время увеличить -Xmx/-Xms. В противном случае пришло время собирать и анализировать кучу кучи, чтобы идентифицировать память.

После решения проблемы рабочего набора 3Gb вы можете найти следующий совет: С моей точки зрения, стоит использовать обычный (не инкрементный) CMS-режим и сокращение NewSize.

1) Инкрементный режим предназначен для компьютеров с одним процессором, когда поток CMS дает CPU другим потокам.

Если у вас есть запасной процессор (например, вы используете многоядерную машину), лучше выполнить GC в фоновом режиме без выходов.

Таким образом, я бы рекомендовал удалить -XX: + CMSIncrementalMode.

2) -XX: CMSInitiatingOccupancyFraction = 60 сообщает CMS, чтобы запустить фоновый GC после того, как OLD gen заполнен на 60%.

Если в куче есть мусор, и CMS не справляется с этим, имеет смысл снизить CMSInitiatingOccupancyFraction. Например, -XX: CMSInitiatingOccupancyFraction = 30, поэтому CMS начнет параллельную сборку, когда старый ген будет заполнен на 30%. В настоящее время трудно сказать, так ли это, потому что у вас просто нет мусора в куче.

3) Похоже, "расширенное владение" не помогает - объекты просто не вымирают даже после 7-8 тенгеров. Я бы рекомендовал уменьшить SurvivorRatio (например, SurvivorRatio = 2 или просто удалить опцию и придерживаться значения по умолчанию). Это уменьшило бы количество штампов, в результате чего уменьшились бы незначительные паузы gc.

4) -XX: NewSize = 2G. Вы пытались снизить значения для NewSize? Скажем, NewSize = 512 м. Это должно уменьшить незначительные приостановки gc и сделать акции молодыми > старыми менее массивными, упрощая работу для CMS.

Ответ 4

Размеры вашего оставшегося в живых не уменьшаются, если вообще - в идеале они должны резко уменьшаться, потому что вы хотите, чтобы меньшинство предметов выжило достаточно долго, чтобы добраться до Старого поколения.

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

(У вас есть какие-либо опции для изменения приложения, кстати, или вы можете только изменить настройки GC? Также могут быть настройки Tomcat, которые будут иметь эффект...)

Ответ 5

Ниже приведена моя настройка для 4-х основных ящиков Linux.

По моему опыту вы можете настроить -XX: NewSize -XX: MaxNewSize -XX: GCTimeRatio для достижения высокой пропускной способности и низкой латентности.

-сервер
-Xms2048m
-Xmx2048m
-Dsun.rmi.dgc.client.gcInterval = 86400000
-Dsun.rmi.dgc.server.gcInterval = 86400000
-XX: + AggressiveOpts
-XX: GCTimeRatio = 20
-XX: + UseParNewGC
-XX: ParallelGCThreads = 4
-XX: + CMSParallelRemarkEnabled
-XX: ParallelCMSThreads = 2
-XX: + CMSScavengeBeforeRemark
-XX: + UseConcMarkSweepGC
-XX: + UseCMSInitiatingOccupancyOnly
-XX: CMSInitiatingOccupancyFraction = 50
-XX: NewSize = 512m
-XX: MaxNewSize = 512m
-XX: PermSize = 256m
-XX: MaxPermSize = 256m
-XX: SurvivorRatio = 90
-XX: TargetSurvivorRatio = 90
-XX: MaxTenuringThreshold = 15
-XX: MaxGCMinorPauseMillis = 1
-XX: MaxGCPauseMillis = 5
-XX: + PrintGCDateStamps
-XX: + PrintGCDetails
-XX: + PrintTenuringDistribution
-Xloggc:./logs/gc.log