denixx 22 мар 2015 в 19:10

Как бороться с OutOfMemoryError на практике, или ох уж мне эти базы данных

17 мин

74K

Java*Отладка*

Туториал

+48

Комментарии 31

TimReset 22 мар 2015 в 22:22

Как бы банально не звучало, но — Спасибо за статью! У нас как раз в пятницу WebLogic падал с OOM. Так что статья вовремя — завтра будем её использовать. Кстати, по повду jmap, для дампа целевое приложение не нужно запускать с какими то параметрами? Т.е. вот работает приложение в проде без опций heap dump и можно ли с помощью jmap сделать дамп памяти это приложения?

denixx 22 мар 2015 в 22:29

Пожалуйста, я буду рад, если поможет.
Если я правильно разобрался в проблемной области, то jmap требуется запускать от того же пользователя, под которым запущено приложение. Отсюда танцы с бубном вокруг PsExec под виндой, ведь томкет в ней запускается от системы в случае, если устанавливался как служба.
Да, jmap не связан никак с опцей автоматической генерации дампа.

hssergey 22 мар 2015 в 22:48

Самое коварное — это когда память течет и заканчивается потихоньку. В этом случае потоки еще не падают с ООМ, но все большую часть процессорного времени начинает отжирать GC. В результате сервер «встает колом» — ошибок нет, но все повисает, пользователи отваливаются, система фактически перестает реагировать на внешние раздражители. Дамп памяти «наживую» создать при этом невозможно, штатно завершить работу сервера — тоже. То есть если не мониторить heap, то выглядит это как повисание сервера намертво через несколько дней работы…

denixx 22 мар 2015 в 22:54

Дамп памяти «наживую» создать при этом невозможно

Ну, может помочь ключ -F для jmap ;) http://docs.oracle.com/javase/7/docs/technotes/tools/share/jmap.html
В этом случае игнорируется параметр live.

tagir_valeev 23 мар 2015 в 05:00

Если память течёт совсем медленно, мы обычно создаём на живую два дампа с помощью jmap с некоторым интервалом времени, потом внимательно смотрим разницу.

teran 22 мар 2015 в 23:16

Начиная с седьмой версии tomcat в него впилили новый connection pool — tomcat.apache.org/tomcat-7.0-doc/jdbc-pool.html, не пробовали? Пользуемся им давно, нареканий пока не было.

denixx 23 мар 2015 в 12:10

Отвечаю, что использовать не пробовали, но спасибо, что подсказали, когда появится время — надо бы посмотреть, что он из себя представляет.
Скажу лишь, что под капотом DBCP 2.0 уже располагается commons-pool2, это было причиной переименования параметров.
В pom'нике в ветке trunk проекта commons-dbcp2 сейчас наблюдается строчка
<commons.pool.version>2.3</commons.pool.version>
Если прогуляться в класс http://svn.apache.org/viewvc/commons/proper/pool/tags/POOL_2_3/src/main/java/org/apache/commons/pool2/impl/GenericObjectPool.java?view=markup, то в строке 1132 можно увидеть строчку

private final LinkedBlockingDeque<PooledObject<T>> idleObjects;

Ну и в методе «public T borrowObject(long borrowMaxWaitMillis)» (строка 411) эта очередь активно используется.
Думаю, что DBCP 2 должен быть быстрее, чем 1.4, и у меня даже есть желание перейти на DBCP 2+.
Надо бы посмотреть содержимое и попробовать провести бенчмарк, который предоставляет разработчик HikariCP, чтобы понять, каков этот коэффициент ускорения.
По предоставленной Вами ссылке так и написано в первых двух пунктах, что мол «Note that this does not apply to Commons DBCP 2.x.».

ilukyanov 22 мар 2015 в 23:47

Есть один неочевидный и коварный аспект Out of Memory ошибок, который может натворить много бед в продакшене и о котором стоит сказать. Суть в том, что в зависимости от реализации приложение в полумертвом OOM-состоянии может нормально отвечать на запросы внешнего мониторинга (например, отдавать страницу 200 ОК или возвращать утвердительный ответ о работоспособности иным способом, например по JMS), при этом де-факто уже не являясь работоспособным.

Поэтому если речь идет о mission-critical задачах, может быть уместно устанавливать дефолтный эксепшн хендлер (см. Thread.setDefaultUncaughtExceptionHandler()) и вызывать System.exit() как только прилетает упоминание OutOfMemoryError.

tagir_valeev 23 мар 2015 в 05:17

А чем поможет System.exit в таком случае? С полуживого приложения проще собрать диагностику и понять, что случилось, чем с завершившегося.

ilukyanov 23 мар 2015 в 12:55

Тем, что мониторинг обнаружит неработоспособность приложения сразу, а не через несколько часов например.

denixx 23 мар 2015 в 13:40

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

ilukyanov 23 мар 2015 в 13:52

Как именно обрабатывать событие в обработчике Thread.UncaughtExceptionHandler – вопрос второй, можно конечно и в лог писать а потом эти логи парсить. Если конечно есть уверенность в том, что OOM точно не поломает логгинг.

Речь здесь скорее про то, что а) для ловли/логгирования таких ошибок удобно использовать Thread.UncaughtExceptionHandler б) при планировании мониторинга нужно предусматривать кейсы, когда приложение полуживое, но находится в состоянии Out of Memory.

ComodoHacker 23 мар 2015 в 00:23

Не подскажете, как использовать приведенные в статье инструменты для анализа OOM в GUI приложении под Windows?
К примеру, я попытался снять дамп памяти, установил -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=.
Поймал OOM, но дампа не появилось.

denixx 23 мар 2015 в 11:18

Сначала отвечу на Ваш вопрос:
Начну, пожалуй, с примеров кода...

Тестовый класс

import java.io.BufferedReader;
import java.io.IOException;
import java.io.InputStreamReader;

public class TestOOM {
    public static void main(String[] args) throws IOException {
        BufferedReader rdr = new BufferedReader(new InputStreamReader(System.in, "UTF-8"));
        System.out.println("Press Enter to make OOM...");
        rdr.readLine();
        StringBuilder stringBuilder = new StringBuilder();
        while (true) {
            stringBuilder.append("foobarfoobarfoobarfoobarfoobarfoobarfoobarfoobarfoobarfoobarfoobarfoobarfoobar");
        }
    }
}

Запускаем это дело

$ ls
TestOOM.class

$ java -Xmx256m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=. TestOOM
Press Enter to make OOM…

java.lang.OutOfMemoryError: Java heap space
Dumping heap to ./java_pid15967.hprof…
Heap dump file created [85330696 bytes in 0,401 secs]
Exception in thread «main» java.lang.OutOfMemoryError: Java heap space
at java.util.Arrays.copyOf(Arrays.java:2367)
at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:130)
at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:114)
at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:415)
at java.lang.StringBuilder.append(StringBuilder.java:132)
at TestOOM.main(TestOOM.java:16)

В примере выше я указал -Xmx256m, чтобы оно не генерировало дамп памяти на 5 гиг.
В результате в папке, в которой я запускал «приложение», рядом с класс-файлом появился файл java_pid15967.hprof.
В качестве рекомендаций могу посоветовать проверить, что перед параметром HeapDumpOnOutOfMemoryError стоит знак плюс, "-XX:+HeapDumpOnOutOfMemoryError", если будет минус ("-XX:-HeapDumpOnOutOfMemoryError"), то это наоборот, «выключить» (надо, кстати, об этом ещё кое-куда написать, а то чувствую, насоветовал я там человеку...).
К тому же, если есть возможность «подключиться» к процессу, который запущен, с помощью JVVM, то там будет видно, включена ли опция, на вкладке «Overview» будет чёрным по серому написано «Heap dump on OOME: enabled».
Вот, как-то так обстоят дела.

ComodoHacker 23 мар 2015 в 17:57

Спасибо за ответ.
Ключи я указал правильно. Дело еще в том, что приложение не мое и исходников у меня сейчас нет. Возможно там OOME перехватыватеся и как-то обрабатывается. Это может повлиять на создание дампа? Правда в консоли и в логе стектрейс с OOME появляется.

denixx 23 мар 2015 в 18:21

Да, его можно перехватить, выдать в лог, и не пропустить дальше. В консоль и лог OOM в этом случае попадёт, но JVM о нём вроде как не узнает.

Почему перехват Throwable нужно делать с полным знанием дела

import java.io.BufferedReader;
import java.io.IOException;
import java.io.InputStreamReader;
import java.util.logging.Level;
import java.util.logging.Logger;

public class TestOOM {
    private static final Logger LOGGER = Logger.getLogger(TestOOM.class.getName());

    public static void main(String[] args) throws IOException {
        BufferedReader rdr = new BufferedReader(new InputStreamReader(System.in, "UTF-8"));
        LOGGER.info("Press Enter to make OOM...");
        rdr.readLine();
        StringBuilder stringBuilder = new StringBuilder();
        try {
            while (true) {
                stringBuilder.append("foobarfoobarfoobarfoobarfoobarfoobarfoobarfoobarfoobarfoobarfoobarfoobarfoobar");
            }
        } catch (Throwable thr) {
            LOGGER.log(Level.SEVERE, "Here is a some Throwable, printing it and ignoring.", thr);
        }
        LOGGER.info("I am still alive! Press Enter to quit...");
        rdr.readLine();
    }
}

denixx 23 мар 2015 в 18:28

Хотя нет, я соврал, я пропустил заветную строчку «Dumping heap to ./java_pid6902.hprof ...». Однако приложение всё равно «выживает». Возможно, такие конструкции с перехватом Throwable как раз и являются причиной варианта «приложение всё ещё живое, но не отвечает».

Заголовок спойлера

$ java -Xmx256m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=. TestOOM
мар 23, 2015 5:26:35 PM TestOOM main
INFO: Press Enter to make OOM...

java.lang.OutOfMemoryError: Java heap space
Dumping heap to ./java_pid6902.hprof ...
Heap dump file created [85808247 bytes in 0,406 secs]
мар 23, 2015 5:26:36 PM TestOOM main
SEVERE: Here is an some Throwable, printing it and ignoring.
java.lang.OutOfMemoryError: Java heap space
        at java.util.Arrays.copyOf(Arrays.java:2367)
        at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:130)
        at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:114)
        at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:415)
        at java.lang.StringBuilder.append(StringBuilder.java:132)
        at TestOOM.main(TestOOM.java:17)

мар 23, 2015 5:26:36 PM TestOOM main
INFO: I am still alive! Press Enter to quit...

tagir_valeev 23 мар 2015 в 05:23

В MAT OQL тоже можно пользоваться. Он немного мутный, но работает. А ещё там есть полезные вещи типа Merge shortest paths to GC roots. Ну и подсчёт retained size. Довольно магическая штука, не всегда работает как ожидается, но порой выручает.

В одном из приложений мы в обёртку к SQL-соединениям добавили текстовое поле с текстом последнего запроса, выполнявшегося в этом соединении. Исключительно для того, чтобы в дампе памяти его можно было легко найти.

Yupiter 23 мар 2015 в 13:41

Спасибо автору за стать
но вот что меня заинтересовало:

at наш.пакет.СуперКласс.getConnection(СуперКласс.java:100500)
at наш.пакет.СуперКласс.плохойПлохойМетод(СуперКласс.java:100800)

это реальные цифры? это сгенерированный код? мне очень трудно представить как иначе класс мог бы разрастись до столь не вменяемых размеров

denixx 23 мар 2015 в 13:59

Нет, класс вполне обычный, я просто скрыл содержимое стектрейса, а в качестве номеров строк указал сие магическое число, это просто отсылка к мему "Стопицот".
Я даже сомневаюсь, что во всём проекте столько строк наберётся.

vladimir_dolzhenko 23 мар 2015 в 18:31

Еще стоит посмотреть доклад Володи Ситникова — Анализ дампов памяти Java приложений

Там и про jvisualvm, и про MAT, и про OQL и прикрученный Володей SQL движок к MAT'у, так, что можно писать куда более интересные запросы.

denixx 23 мар 2015 в 23:28

Отлично, как раз то, что хотелось узнать про MAT. Благодарю!

НЛО прилетело и опубликовало эту надпись здесь

tagir_valeev 25 мар 2015 в 14:08

Эти проценты от общего числа упавших приложений или от общего числа протестированных? А тесты на какой версии Java проводились? Теоретически с седьмой количество PermGen space ошибко должно уменьшиться (а в восьмой и вовсе исчезнуть).

Иногда разумно продолжить работу приложения с помощью логирования catch Throwable. Есть шансы, что именно в этом try-блоке было выделено очень много памяти и при проваливании в catch она освободится.

Я стараюсь писать catch Throwable где-нибудь на самом верху — общий try-catch для фоновых задач, например. Тогда при OOM умрёт поток с фоновой задачей, но есть шансы, что выживет приложение. Обычно catch Throwable направлен на ловлю других ошибок — например, корявый деплой привёл к несоответствию версий библиотек и выпало что-нибудь вроде NoSuchMethodError. В современном мире такая ошибка не хуже NullPointerException. Ну то есть это откровенный баг и скорее всего какая-то подсистема полностью не функционирует, но не повод из-за него класть весь сервер. Или StackOverflowError — его тоже можно пережить. Возможно, стоит подходить более дифференцировано к Error-исключениям и обрабатывать OOM по особенному. Слать СМС-ку админу, например :-)

НЛО прилетело и опубликовало эту надпись здесь

denixx 28 окт 2015 в 15:42

//Добавлен UPD2.

ilukyanov 28 окт 2015 в 17:40

// Хозяйке на заметку
С помощью ключа -XX:OnOutOfMemoryError=«kill -9 %p» можно повесить на OutOfMemory ошибку определенные действия, например jstack, jsmap и kill, упакованные в shell-скрипт.

Кавычки конечно должны быть не елочки, а самые обыкновенные :)

grossws 28 окт 2015 в 17:52

Тот же apache solr с 5 версии так и делает. OOM там может и не повлиять на доступность на чтение, в отличии от доступности на запись.

denixx 19 окт 2016 в 09:55

UPD 3: markt в мейлинг-листе томкета отвечал на вопрос, какого чёрта в томкете два коннекшн-пула одновременно (tomcat-jdbc и одновременно DBCP, и почему внезапно в восьмом томкете DBCP стал выгоднее): http://mail-archives.apache.org/mod_mbox/tomcat-users/201506.mbox/%3C556EC74A.5040306%40apache.org%3E.

denixx 19 окт 2016 в 10:00

Извиняюсь, не успел отредактировать, вот кликабельная ссылка: http://mail-archives.apache.org/mod_mbox/tomcat-users/201506.mbox/%3C556EC74A.5040306%40apache.org%3E

denixx 30 ноя 2016 в 15:54

objid: «0x» + parseInt(objectid(x)).toString(16)

Зарегистрируйтесь на Хабре, чтобы оставить комментарий