Отслеживание проблемы утечки памяти / сборки мусора в Java

Это проблема, которую я пытаюсь отследить уже пару месяцев. У меня запущено java-приложение, которое обрабатывает xml-каналы и сохраняет результат в базе данных. Периодически возникали проблемы с ресурсами, которые очень трудно отследить.

Предыстория: в производственном ящике (где проблема наиболее заметна) у меня нет особенно хорошего доступа к ящику, и я не смог запустить Jprofiler. Это 64-битный четырехъядерный компьютер объемом 8 ГБ, работающий под управлением centos 5.2, tomcat6 и java 1.6.0.11. Все начинается с этих java-оптов

JAVA_OPTS="-server -Xmx5g -Xms4g -Xss256k -XX:MaxPermSize=256m -XX:+PrintGCDetails -
XX:+PrintGCTimeStamps -XX:+UseConcMarkSweepGC -XX:+PrintTenuringDistribution -XX:+UseParNewGC"

Стек технологий следующий:

• Centos, 64-разрядная версия 5.2
• Java 6u11
• Tomcat 6
• Весна / WebMVC 2.5
• Гибернация 3
• Кварц 1.6.1
• DBCP 1.2.1
• MySQL 5.0.45
• Ehcache 1.5.0
• (и, конечно же, множество других зависимостей, в частности библиотеки jakarta-commons)

Ближе всего к воспроизведению проблемы я могу подойти к 32-битной машине с меньшими требованиями к памяти. Это я контролирую. Я исследовал это до смерти с помощью JProfiler и исправил многие проблемы с производительностью (проблемы с синхронизацией, предварительная компиляция / кеширование запросов xpath, сокращение пула потоков и удаление ненужной предварительной выборки гибернации, а также чрезмерное «нагревание кеша» во время обработки).

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

Проблема: кажется, что JVM полностью игнорирует настройки использования памяти, заполняет всю память и перестает отвечать. Это проблема для клиента, который ожидает регулярного опроса (5-минутный базис и 1-минутный повтор), а также для наших операционных групп, которые постоянно получают уведомления о том, что ящик перестал отвечать, и должны его перезапустить. На этом ящике больше ничего значительного нет.

Проблема возникает как вывоз мусора. Мы используем сборщик ConcurrentMarkSweep (как указано выше), потому что исходный сборщик STW вызывал тайм-ауты JDBC и становился все более медленным. Журналы показывают, что по мере увеличения использования памяти это начинает вызывать сбои cms и возвращается к исходному сборщику остановки мира, который затем, кажется, не собирает должным образом.

Однако при работе с jprofiler кнопка «Run GC», кажется, хорошо очищает память, а не показывает увеличивающуюся площадь, но, поскольку я не могу подключить jprofiler напрямую к производственной коробке, и разрешение проверенных горячих точек, похоже, не работает, я остался с вуду настройки слепой сборки мусора.

Что я пробовал:

• Профилирование и устранение горячих точек.
• Использование сборщиков мусора STW, Parallel и CMS.
• Работа с минимальным / максимальным размером кучи с шагом 1 / 2,2 / 4,4 / 5,6 / 6.
• Запуск с постоянным пространством с шагом 256 МБ до 1 ГБ.
• Множество комбинаций вышеперечисленного.
• Я также проконсультировался с JVM [справочник по настройке] (http://java.sun.com/javase/technologies/hotspot/gc/gc_tuning_6.html), но не могу найти ничего, объясняющего это поведение или каких-либо примеров _which_ настройки параметры для использования в такой ситуации.
• Я также (безуспешно) попробовал jprofiler в автономном режиме, подключившись к jconsole, visualvm, но я не могу найти ничего, что могло бы интерпретировать мои данные журнала gc.

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

Может ли кто-нибудь дать какой-либо совет относительно:
a) Почему JVM использует 8 физических гигабайт и 2 ГБ пространства подкачки, когда он настроен на максимальное значение менее 6.
b) Ссылка на настройку GC, которая фактически объясняет или дает разумные примеры о том, когда и с какими настройками использовать расширенные коллекции.
c) Ссылка на наиболее распространенные утечки памяти Java (я понимаю невостребованные ссылки, но я имею в виду на уровне библиотеки / фреймворка или что-то еще в структурах данных, таких как хэш-карты).

Спасибо за любую информацию, которую вы можете предоставить.

ИЗМЕНИТЬ
Эмиль Х:
1) Да, мой кластер разработки является зеркалом производственных данных, вплоть до медиа-сервера. Основное отличие - это 32/64 бит и объем доступной оперативной памяти, который я не могу легко воспроизвести, но код, запросы и настройки идентичны.

2) Есть некоторый унаследованный код, который полагается на JaxB, но при переупорядочении заданий, чтобы попытаться избежать конфликтов планирования, это выполнение обычно исключается, поскольку оно выполняется один раз в день. Основной синтаксический анализатор использует запросы XPath, которые вызывают пакет java.xml.xpath. Это было источником нескольких горячих точек, для одного запросы не были предварительно скомпилированы, а для двух ссылки на них были в жестко запрограммированных строках. Я создал потокобезопасный кеш (hashmap) и выделил ссылки на запросы xpath как окончательные статические строки, что значительно снизило потребление ресурсов. Запросы по-прежнему являются значительной частью обработки, но это должно быть так, потому что это основная ответственность приложения.

3) Дополнительное примечание, другим основным потребителем являются операции с изображениями из JAI (повторная обработка изображений из канала). Я не знаком с графическими библиотеками Java, но из того, что я обнаружил, они не особо протекают.

(спасибо за ответы, ребята!)

ОБНОВЛЕНИЕ:
мне удалось подключиться к производственному экземпляру с помощью VisualVM, но он отключил параметр визуализации GC / run-GC (хотя я мог просматривать его локально). Интересная вещь: распределение кучи виртуальной машины подчиняется JAVA_OPTS, а фактическая выделенная куча удобно расположена на 1-1,5 гигабайт и, похоже, не протекает, но мониторинг уровня коробки все еще показывает образец утечки, но это не отражается в мониторинге ВМ. На этом ящике больше ничего не работает, поэтому я в тупике.

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

Я пробовал jmap, пока процесс работал, но обычно это приводило к дальнейшему зависанию jvm, и мне приходилось запускать его с --force. Это приводило к дампам кучи, в которых, казалось, не хватало большого количества данных или, по крайней мере, отсутствовали ссылки между ними. Для анализа я попробовал jhat, который представляет много данных, но не так много, как их интерпретировать. Во-вторых, я попробовал инструмент анализа памяти на основе eclipse ( http://www.eclipse.org/mat/ ), который показал, что куча - это в основном классы, связанные с tomcat.

Проблема заключалась в том, что jmap не сообщал о фактическом состоянии приложения и улавливал только классы при выключении, которые в основном были классами tomcat.

Я попробовал еще несколько раз и заметил, что было очень много объектов модели (на самом деле в 2-3 раза больше, чем было помечено как общедоступные в базе данных).

Используя это, я проанализировал журналы медленных запросов и несколько не связанных с производительностью проблем. Я попробовал очень ленивую загрузку ( http://docs.jboss.org/hibernate/core/3.3/reference/en/html/performance.html ), а также заменил несколько операций гибернации прямыми запросами jdbc (в основном там, где он имел дело с загрузкой и работой с большими коллекциями - замены jdbc просто работали непосредственно с таблицами соединения) и заменяли некоторые другие неэффективные запросы, которые mysql регистрировал.

Эти шаги улучшили производительность внешнего интерфейса, но все еще не решили проблему утечки, приложение все еще было нестабильным и работало непредсказуемо.

Наконец, я нашел вариант: -XX: + HeapDumpOnOutOfMemoryError. В итоге получился очень большой (~ 6,5 ГБ) файл hprof, который точно отображал состояние приложения. Как ни странно, файл был настолько большим, что jhat не мог его проанализировать, даже на коробке с 16 ГБ оперативной памяти. К счастью, MAT смогла построить несколько красивых графиков и показать некоторые лучшие данные.

На этот раз выделялся единственный кварцевый поток, занимавший 4,5 ГБ из 6 ГБ кучи, и большую часть из них составлял StatefulPersistenceContext в спящем режиме ( https://www.hibernate.org/hib_docs/v3/api/org/hibernate /engine/StatefulPersistenceContext.html ). Этот класс используется внутри спящего режима в качестве основного кеша (я отключил кеши второго уровня и кеши запросов, поддерживаемые EHCache).

Этот класс используется для включения большинства функций спящего режима, поэтому его нельзя напрямую отключить (вы можете обойти его напрямую, но Spring не поддерживает сеанс без сохранения состояния), и я был бы очень удивлен, если бы у него был такой большая утечка памяти в зрелом продукте. Так почему он протекает сейчас?

Ну, это была комбинация вещей: экземпляры пула кварцевых потоков с определенными вещами являются threadLocal, spring внедрял фабрику сеансов, которая создавала сеанс в начале жизненного цикла кварцевых потоков, который затем повторно использовался для запуска различные кварцевые задания, которые использовали сеанс гибернации. Затем Hibernate кэшировал в сеансе, что является его ожидаемым поведением.

Проблема в том, что пул потоков никогда не освобождает сеанс, поэтому спящий режим оставался резидентным и поддерживал кеш для жизненного цикла сеанса. Поскольку здесь использовалась поддержка шаблонов спящего режима пружин, явного использования сеансов не было (мы используем иерархию dao -> manager -> driver -> quartz-job, dao вводится с конфигурациями гибернации через spring, поэтому операции делается прямо по шаблонам).

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

Решение: создать метод dao, который явно вызывает session.flush () и session.clear (), и вызывать этот метод в начале каждого задания.

Приложение работает уже несколько дней без проблем с мониторингом, ошибок памяти или перезапусков.

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

Можете ли вы запустить производственную коробку с включенным JMX?

-Dcom.sun.management.jmxremote
-Dcom.sun.management.jmxremote.port=<port>
...

Мониторинг и управление с помощью JMX

А потом прикрепить с помощью JConsole VisualVM ?

Можно ли делать дамп кучи с помощью jmap ?

Если да, вы можете проанализировать дамп кучи на предмет утечек с помощью JProfiler (у вас уже есть), jhat , VisualVM, Eclipse MAT . Также сравните дампы кучи, которые могут помочь найти утечки / шаблоны.

И, как вы упомянули, jakarta-commons. При использовании jakarta-commons-logging возникает проблема, связанная с удержанием загрузчика классов. Для хорошего прочтения этого чека

День из жизни охотника за утечками памяти ( release(Classloader))

Похоже, что утечка памяти, кроме кучи, вы упоминаете, что куча остается стабильной. Классическим кандидатом является permgen (постоянная генерация), которая состоит из двух вещей: загруженных объектов класса и интернированных строк. Поскольку вы сообщаете о подключении к VisualVM, вы должны иметь возможность видеть количество загруженных классов, если происходит постоянное увеличение загруженных классов (важно, visualvm также показывает общее количество когда-либо загруженных классов, это нормально, если оно увеличивается, но количество загруженных классов должно стабилизироваться через определенное время).

Если это действительно утечка permgen, то отладка становится более сложной, поскольку инструменты для анализа permgen скорее отсутствуют по сравнению с кучей. Лучше всего запустить на сервере небольшой скрипт, который неоднократно (каждый час?) Вызывает:

jmap -permstat <pid> > somefile<timestamp>.txt

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

Как только вы определили определенные классы как загружаемые, а не выгружаемые, вы можете мысленно выяснить, где они могут быть сгенерированы, иначе вы можете использовать jhat для анализа дампов, созданных с помощью jmap -dump. Я сохраню это для будущего обновления, если вам понадобится информация.

Я бы поискал напрямую выделенный ByteBuffer.

Из файла javadoc.

Прямой байтовый буфер может быть создан путем вызова фабричного метода allocateDirect этого класса. Буферы, возвращаемые этим методом, обычно имеют несколько более высокие затраты на выделение и освобождение, чем непрямые буферы. Содержимое прямых буферов может находиться вне обычной кучи, собираемой мусором, поэтому их влияние на объем памяти приложения может быть неочевидным. Поэтому рекомендуется выделять прямые буферы в первую очередь для больших долгоживущих буферов, которые являются предметом собственных операций ввода-вывода базовой системы. В общем случае лучше всего выделять прямые буферы только тогда, когда они дают ощутимый выигрыш в производительности программы.

Возможно, код Tomcat использует это do для ввода-вывода; настроить Tomcat для использования другого коннектора.

В противном случае у вас может быть поток, который периодически выполняет System.gc (). "-XX: + ExplicitGCInvokesConcurrent" может быть интересным вариантом.

Есть JAXB? Я считаю, что JAXB - это средство для перманентного пространства.

Кроме того, я считаю, что visualgc , теперь поставляемый с JDK 6, является отличным способом увидеть, что происходит в памяти. Он прекрасно показывает райское пространство, пространство поколений и перманентное поведение, а также переходное поведение GC. Все, что вам нужно, это PID процесса. Может быть, это поможет вам в работе над JProfile.

А как насчет аспектов трассировки / ведения журнала Spring? Может быть, вы можете написать простой аспект, применить его декларативно и таким образом сделать профилировщик для бедняков.

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

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

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

У меня была такая же проблема, но с некоторыми отличиями ..

Моя технология следующая:

grails 2.2.4

tomcat7

кварц-плагин 1.0

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

Еще одна вещь, которую следует учитывать, - это плагин quartz, вводящий сеанс гибернации в кварцевые потоки, как говорит @liam, и кварцевые потоки все еще живы, пока я не закончу приложение.

Моя проблема заключалась в ошибке ORM grails в сочетании с тем, как плагин обрабатывает сеанс и два моих источника данных.

В плагине Quartz есть слушатель для запуска и уничтожения сеансов гибернации.

public class SessionBinderJobListener extends JobListenerSupport {

    public static final String NAME = "sessionBinderListener";

    private PersistenceContextInterceptor persistenceInterceptor;

    public String getName() {
        return NAME;
    }

    public PersistenceContextInterceptor getPersistenceInterceptor() {
        return persistenceInterceptor;
    }

    public void setPersistenceInterceptor(PersistenceContextInterceptor persistenceInterceptor) {
        this.persistenceInterceptor = persistenceInterceptor;
    }

    public void jobToBeExecuted(JobExecutionContext context) {
        if (persistenceInterceptor != null) {
            persistenceInterceptor.init();
        }
    }

    public void jobWasExecuted(JobExecutionContext context, JobExecutionException exception) {
        if (persistenceInterceptor != null) {
            persistenceInterceptor.flush();
            persistenceInterceptor.destroy();
        }
    }
}

В моем случае persistenceInterceptorэкземпляры AggregatePersistenceContextInterceptor, и у него был список HibernatePersistenceContextInterceptor. По одному для каждого источника данных.

Каждая операция AggregatePersistenceContextInterceptorпередается в HibernatePersistence без каких-либо изменений или обработок.

Когда мы звонки init()на HibernatePersistenceContextInterceptorнего увеличивает переменный статическую ниже

private static ThreadLocal<Integer> nestingCount = new ThreadLocal<Integer>();

Я не знаю, зачем нужен этот статический счет. Я просто знаю, что он увеличился в два раза, по одному на источник данных, из-за AggregatePersistenceреализации.

Пока здесь я просто объясню cenario.

Проблема возникает сейчас ...

Когда моя работа с кварцем завершается, плагин вызывает слушателя, чтобы очистить и уничтожить сеансы гибернации, как вы можете видеть в исходном коде SessionBinderJobListener.

Сброс происходит идеально, но не уничтожается, потому HibernatePersistenceчто перед закрытием сеанса гибернации выполняется одна проверка ... Он проверяет, nestingCountявляется ли значение больше, чем 1. Если ответ положительный, он не закрывает сеанс.

Упрощение того, что сделал Hibernate:

if(--nestingCount.getValue() > 0)
    do nothing;
else
    close the session;

Это основа моей утечки памяти. Кварцевые потоки все еще живы со всеми объектами, используемыми в сеансе, потому что ORM grails не закрывает сеанс из-за ошибки, вызванной тем, что у меня есть два источника данных.

Чтобы решить эту проблему, я настраиваю слушателя для вызова clear перед уничтожением и дважды вызываю destroy (по одному для каждого источника данных). Обеспечение того, чтобы мой сеанс был чистым и уничтоженным, и, если уничтожение не удалось, по крайней мере, он был чист.