Java ConcurrentMarkSweep сборщик мусора не удаляет весь мусор

Question

Краткая форма: сборщик мусора CMS, кажется, не в состоянии собирать постоянно увеличивающееся количество мусора; в конечном итоге наша JVM заполняется, и приложение перестает отвечать на запросы. Форсирование GC с помощью внешнего инструмента (JConsole или jmap -histo:live) очищает его один раз.

ОБНОВЛЕНИЕ: проблема, кажется, связана с плагином JTop для JConsole; если мы не запустим JConsole или не запустим его без плагина JTop, поведение исчезнет.

(Технические примечания: мы запускаем Sun JDK 1.6.0_07, 32-разрядный, на Linux 2.6.9. Обновление версии JDK на самом деле не вариант, если только это не является главной причиной. Кроме того, наша система не подключен к машине, доступной через Интернет, поэтому снимки экрана JConsole и т. д. не подходят.)

В настоящее время мы запускаем нашу JVM со следующими флагами:

-server -Xms3072m -Xmx3072m -XX:NewSize=512m -XX:MaxNewSize=512m 
-XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+CMSParallelRemarkEnabled 
-XX:CMSInitiatingOccupancyFraction=70 
-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps 
-XX:+DisableExplicitGC

Наблюдая за графиком памяти в JConsole, мы видим полный GC, который запускается каждые ~15 минут или около того в течение первых нескольких часов жизни нашего приложения; после каждого полного GC все больше и больше памяти все еще используется. Через несколько часов система переходит в устойчивое состояние, когда в CMS старого поколения примерно 2 ГБ используемой памяти.

Это звучит как классическая утечка памяти, за исключением того, что если мы используем какой-либо инструмент, который вызывает полный сборщик мусора (нажатие кнопки "собрать мусор" в JConsole или запуск jmap -histo:liveи т. д.), старый ген внезапно падает до ~500 МБ, и наше приложение снова становится отзывчивым в течение следующих нескольких часов (в течение этого времени продолжается та же самая картина - после каждого полного GC все больше и больше старого поколения заполнено).

Одна вещь, на которую следует обратить внимание: в JConsole указанный счетчик GC ConcurrentMarkSweep будет оставаться равным 0, пока мы не принудительно настроим GC с помощью jconsole/jmap/etc.

С помощью jmap -histo а также jmap -histo:live по порядку я могу определить, что явно не собранные объекты состоят из:

• несколько миллионов HashMapс и массивы HashMap$Entry (в соотношении 1:1)
• несколько миллионов Vectors и объектные массивы (соотношение 1:1 и примерно столько же, сколько число хэш-карт)
• несколько миллионов HashSet, Hashtable, а также com.sun.jmx.remote.util.OrderClassLoaders, а также массивы Hashtable$Entry (примерно одинаковое число каждого; примерно вдвое меньше, чем HashMaps и Vectors)

Ниже приводятся некоторые выдержки из вывода GC; моя интерпретация, по-видимому, заключается в том, что CMS GC прерывается, не переходя к GC "останови мир". Я как-то неверно истолковал этот вывод? Есть ли что-то, что могло бы вызвать это?

Во время нормальной работы выходные блоки CMS GC выглядят примерно так:

36301.827: [GC [1 CMS-initial-mark: 1856321K(2621330K)] 1879456K(3093312K), 1.7634200 secs] [Times: user=0.17 sys=0.00, real=0.18 secs]
36303.638: [CMS-concurrent-mark-start]
36314.903: [CMS-concurrent-mark: 7.804/11.264 secs] [Times: user=2.13 sys=0.06, real=1.13 secs]
36314.903: [CMS-concurrent-preclean-start]
36314.963: [CMS-concurrent-preclean: 0.037/0.060 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
36314.963: [CMS-concurrent-abortable-preclean-start]
36315.195: [GC 36315.195: [ParNew: 428092K->40832K(471872K), 1.1705760 secs] 2284414K->1897153K(3093312K), 1.1710560 secs] [Times: user=0.13 sys=0.02, real=0.12 secs]
CMS: abort preclean due to time 36320.059: [CMS-concurrent-abortable-preclean: 0.844/5.095 secs] [Times: user=0.74 sys=0.05, real=0.51 secs]
36320.062: [GC[YG occupancy: 146166 K (471872 K)]36320.062: [Rescan (parallel), 1.54078550 secs]36321.603: [weak refs processing, 0.0042640 secs] [1 CMS-remark: 1856321K(2621440K)] 2002488K(3093312K), 1.5456150 secs] [Times: user=0.18 sys=0.03, real=0.15 secs]
36321.608: [CMS-concurrent-sweep-start]
36324.650: [CMS-concurrent-sweep: 2.686/3.042 secs] [Times: uesr=0.66 sys=0.02, real=0.30 secs]
36324.651: [CMS-concurrent-reset-start]
36324.700: [CMS-concurrent-reset: 0.050/0.050 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

и это все; следующая строка будет следующей ParNew GC.

Когда мы заставляем сборщик мусора с помощью jmap -histo:live, мы вместо этого получаем:

48004.088: [CMS-concurrent-mark: 8.012/8.647 secs] [Times: user=1.15 sys=0.02, real=0.87 secs]
(concurrent mode interrupted)

сопровождаемый ~125 строками формы ниже: (некоторые GeneratedMethodAccessor, некоторые GeneratedSerializationConstructorAccessor, некоторые GeneratedConstructorAccessor и т. д.)

[Unloading class sun.reflect.GeneratedMethodAccessor3]

с последующим:

: 1911295K->562232K(2621440K), 15.6886180 secs] 2366440K->562232K(3093312K), [CMS Perm: 52729K->51864K(65536K)], 15.6892270 secs] [Times: user=1.55 sys=0.01, real=1.57 secs]

Заранее спасибо!

Answer 1

com.sun.jmx.remote.util.OrderClassLoader используется на уровне удаленного доступа для JMX, и быстрый обзор кода показывает, что они созданы как часть процесса демаршаллинга для удаленных запросов внутри JVM. Время жизни этих загрузчиков классов будет напрямую связано с временем жизни того, что было разобранно, так что, когда больше не будет никаких ссылок на эту вещь, загрузчик классов может быть освобожден.

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

Я предполагаю, что, возможно, есть ошибка в реализации JMX (кажется маловероятной в относительно современной JVM), или, возможно, у вас есть несколько пользовательских MBean-компонентов или вы используете некоторые пользовательские инструменты JMX, которые вызывают проблему. Но в конечном счете, я подозреваю, что OrderClassLoader, вероятно, является "красной селедкой", и проблема кроется в другом месте (сломанный GC или какая-то другая утечка).

Answer 2

Технические примечания: мы работаем под управлением Sun JDK 1.6.0_07, 32-разрядная, на Linux 2.6.9. Обновление версии JDK на самом деле не вариант, если только это не является главной причиной.

Несколько новых версий Java были обновлены для сборщика мусора CMS. В частности, 6u12, 6u14 и 6u18.

Я не эксперт в GC, но я предполагаю, что предварительные исправления в 6u14 могут решить проблему, которую вы видите. Конечно, я мог бы сказать то же самое о багах разгрузки класса 6u18. Как я уже сказал, я не эксперт в GC.

Есть исправления для:

• 6u10: (влияет на 6u4+) CMS никогда не очищает ссылки, когда -XX: + ParallelRefProcEnabled
• 6u12: CMS: неправильное кодирование массивов переполненных объектов во время одновременной предварительной очистки
• 6u12: CMS: неправильная обработка переполнения при использовании параллельной параллельной маркировки
• 6u14: CMS: ошибка подтверждения "is_cms_thread == Thread:: current () -> is_ConcurrentGC_thread ()"
• 6u14: CMS: Нужна CMSInitiatingPermOccupancyFraction для Перми, в отличие от CMSInitiatingOccupancyFraction
• 6u14: утверждение CMS: пропущено обновление _concurrent_iteration_safe_limit
• 6u14: CMS: неправильная обработка переполнения во время предварительной очистки списков литературы
• 6u14: утверждение SIGSEGV или (! Is_null(v),"значение oop никогда не может быть нулевым") при работе с CMS и COOP
• 6u14: CMS: Livelock в CompactibleFreeListSpace:: block_size ().
• 6u14: заставить CMS работать со сжатыми ой
• 6u18: CMS: дамп ядра с -XX: + UseCompressedOops
• 6u18: CMS: ошибки, связанные с выгрузкой классов
• 6u18: CMS: ReduceInitialCardMarks небезопасны при наличии предварительной очистки cms
• 6u18: [Регрессия] -XX:NewRatio с -XX:+UseConcMarkSweepGC вызывает фатальную ошибку
• 6u20: метки карты могут быть отложены слишком долго

В дополнение ко всему вышесказанному, 6u14 также представил сборщик мусора G1, хотя он все еще находится в стадии тестирования. G1 предназначен для замены CMS в Java 7.

G1 может использоваться в Java 6u14 и новее со следующими параметрами командной строки:

-XX:+UnlockExperimentalVMOptions -XX:+UseG1GC

Answer 3

Я бы начал с чего-то гораздо более простого, например:

-server -Xms3072m -Xmx3072m -XX:+UseParallelOldGC -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps 

И посмотрите, соответствует ли это вашим потребностям.

Answer 4

Похоже, вы строите объекты, которые указывают на их владельцев ( A указывает на B указывает на A). Это приводит к тому, что число ссылок остается больше нуля, поэтому сборщик мусора не может их очистить. Вам нужно разорвать цикл, когда вы отпустите их. Обнуление ссылки в A или B решит проблему. Это работает даже в увеличенном виде выглядит ( A -> B -> C -> D -> A). Векторы и массивы объектов могут использоваться вашими HashMaps.

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

РЕДАКТИРОВАТЬ: я взглянул на вашу последнюю строку. Возможно, вы захотите увеличить выделение перми.