Есть веб-приложение (Tomcat/Wicket если это важно). Работает сейчас на JVM 7/Tomcat 7 без проблем. Обновил JVM до 8 и Tomcat до 8. Даже памяти больше дал (2 гига, пробовал 4 гига). Работает нормально на вид (жрёт около 500 МБ под нагрузкой). Но в определённый момент перестаёт работать (относительно внезапно, т.е. сутки работало, час назад проверял — нормально, а тут раз и всё). Снял дамп, память кончилась, видно, что вся память ушла в java.lang.ref.Finalizer который пытается финализировать com.sun.xml.internal.bind.v2.runtime.unmarshaller.UnmarshallerImpl. Каждый такой финалайзер весит около 310 КБ ну и их вроде несколько тысяч. В самом приложении используются веб-сервисы. Каких-то изменений кода не было. Нашёл какой-то код этого класса, там что-то вроде

    protected void finalize() throws Throwable {
        try {
            ClassFactory.cleanCache();
        } finally {
            super.finalize();
        }
    }

В какую сторону смотреть? Пока даже не код хочется пофиксить, а обновить JVM и Tomcat, т.е. как-то подобрать настройки GC или кого там, чтобы оно работало как раньше.

Судя по сорцам и com.sun.xml.internal.bind.v2.runtime.unmarshaller.UnmarshallerImpl.finalize и ClassFactory.cleanCache довольно безобидные классы.

Мне кажется, какой-то другой класс залочил finalizer thread, анмаршаллеры накопились в очереди и сожрали память.

Сними дамп потоков в момент проблемы и посмотри чем finalizer thread занимается.

Да, так и есть. Похоже проблема глубже, чем я думал.

Found one Java-level deadlock:
=============================
"http-nio-80-exec-346":
  waiting to lock monitor 0x0000000065b7b038 (object 0x0000000081f50d60, a oracle.jdbc.driver.OracleConnection),
  which is held by "Finalizer"
"Finalizer":
  waiting to lock monitor 0x000000005b03b428 (object 0x0000000081f50e78, a oracle.jdbc.ttc7.TTC7Protocol),
  which is held by "http-nio-80-exec-346"

Java stack information for the threads listed above:
===================================================
"http-nio-80-exec-346":
    at oracle.jdbc.driver.OracleConnection.isLogicalConnection(OracleConnection.java:613)
    - waiting to lock <0x0000000081f50d60> (a oracle.jdbc.driver.OracleConnection)
    at oracle.jdbc.driver.OracleConnection.physicalConnectionWithin(OracleConnection.java:5202)
    at oracle.sql.DatumWithConnection.setPhysicalConnectionOf(DatumWithConnection.java:81)
    at oracle.sql.CLOB.<init>(CLOB.java:165)
    at oracle.sql.CLOB.<init>(CLOB.java:184)
    at oracle.jdbc.ttc7.v8TTIClob.createTemporaryLob(v8TTIClob.java:410)
    at oracle.jdbc.ttc7.TTC7Protocol.createTemporaryLob(TTC7Protocol.java:3283)
    - locked <0x0000000081f50e78> (a oracle.jdbc.ttc7.TTC7Protocol)
    at oracle.sql.LobDBAccessImpl.createTemporaryClob(LobDBAccessImpl.java:755)
    - locked <0x0000000081ea70b8> (a oracle.sql.LobDBAccessImpl)
    at oracle.sql.CLOB.createTemporary(CLOB.java:1011)
    at oracle.sql.CLOB.createTemporary(CLOB.java:956)
    at kz.bimash.mvd.ibdweb.util.OracleClobTypeHandler.setParameter(OracleClobTypeHandler.java:20)
...
"Finalizer":
    at oracle.jdbc.ttc7.TTC7Protocol.close(TTC7Protocol.java:674)
    - waiting to lock <0x0000000081f50e78> (a oracle.jdbc.ttc7.TTC7Protocol)
    at oracle.jdbc.driver.OracleStatement.close(OracleStatement.java:731)
    - locked <0x0000000088023740> (a oracle.jdbc.driver.OracleStatement)
    - locked <0x0000000081f50d60> (a oracle.jdbc.driver.OracleConnection)
    at org.apache.tomcat.dbcp.dbcp2.DelegatingStatement.close(DelegatingStatement.java:149)
    at org.apache.tomcat.dbcp.dbcp2.DelegatingStatement.close(DelegatingStatement.java:149)
    at org.apache.tomcat.dbcp.dbcp2.DelegatingStatement.finalize(DelegatingStatement.java:300)
    at java.lang.System$2.invokeFinalize(System.java:1270)
    at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:102)
    at java.lang.ref.Finalizer.access$100(Finalizer.java:34)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:217)

Found 1 deadlock.

Буду разбираться. Попутно пофиксил некоторые вещи в коде, вроде создаваемых JAXBContext на каждый запрос и утекающих RandomAccessFile Противный баг. Судя по всему где-то не закрыли jdbc Statement. Потом это соединение переиспользовалось в другом потоке. Statement пытаются собрать, он пытается себя закрыть, и при этом дедлочится с другим потоком, который это соединение пытается легитимно использовать. Похоже понятно, откуда Statement утёк, но при анализе дампа обнаружилось несколько Finalizer-ов, которые хотят финализировать незакрытые PreparedStatement-ы, которые вроде должны были быть закрыты MyBatis-ом (если, конечно, в нём нет багов), а также CallableStatement-ы, которые точно обёрнуты в try-with-resources. Вот ведь загадка. Возможно при нехватке памяти что-то там глючит и не может закрыть, других предположений даже нет.

vsb>Судя по всему где-то не закрыли jdbc Statement. Потом это соединение переиспользовалось в другом потоке. Statement пытаются собрать, он пытается себя закрыть, и при этом дедлочится с другим потоком, который это соединение пытается легитимно использовать. Похоже понятно, откуда Statement утёк, но при анализе дампа обнаружилось несколько Finalizer-ов, которые хотят финализировать незакрытые PreparedStatement-ы, которые вроде должны были быть закрыты MyBatis-ом (если, конечно, в нём нет багов),

Посмотри декомпайлером — может там вообще глобальные локи в OracleConnection и TTC7Protocol.

vsb>а также CallableStatement-ы, которые точно обёрнуты в try-with-resources. Вот ведь загадка.

Опять же стоит глянуть декомпайлером — может он в close() сначала лок получает, а потом проверяет закрыто или нет и закрывает открытый. Т.е. твой код вообще не виноват будет.

vsb>Возможно при нехватке памяти что-то там глючит и не может закрыть, других предположений даже нет.

Вот это вряд ли


И вообще, я сейчас Оракл не использую, но по старой памяти чего-то не припоминаю "oracle.jdbc.ttc7.TTC7Protocol" — что это за хрень? Может у тебя драйвер очень старый?

Здравствуйте, bzig, Вы писали:

vsb>>Судя по всему где-то не закрыли jdbc Statement. Потом это соединение переиспользовалось в другом потоке. Statement пытаются собрать, он пытается себя закрыть, и при этом дедлочится с другим потоком, который это соединение пытается легитимно использовать. Похоже понятно, откуда Statement утёк, но при анализе дампа обнаружилось несколько Finalizer-ов, которые хотят финализировать незакрытые PreparedStatement-ы, которые вроде должны были быть закрыты MyBatis-ом (если, конечно, в нём нет багов),

B>Посмотри декомпайлером — может там вообще глобальные локи в OracleConnection и TTC7Protocol.

Там synchronized-методы, лочатся на инстансы соответствующих классов

vsb>>а также CallableStatement-ы, которые точно обёрнуты в try-with-resources. Вот ведь загадка.

B>Опять же стоит глянуть декомпайлером — может он в close() сначала лок получает, а потом проверяет закрыто или нет и закрывает открытый. Т.е. твой код вообще не виноват будет.

Я вообще не уверен, что он виноват (не закрывать Statement-ы это не такой большой грех, их закрывает Connection, а раз Connection в пуле, значит этим должен заниматься пул в момент освобождения коннекта, а не когда GC собирает), но мне от этого не легче, оракловые драйверы переписывать я точно не буду

vsb>>Возможно при нехватке памяти что-то там глючит и не может закрыть, других предположений даже нет.

B>Вот это вряд ли

Ну вообще да, тогда, в DelegatingStatement там closed = true стоит в finally, должен сработать при любом раскладе. Значит это останется загадкой.

B>И вообще, я сейчас Оракл не использую, но по старой памяти чего-то не припоминаю "oracle.jdbc.ttc7.TTC7Protocol" — что это за хрень? Может у тебя драйвер очень старый?

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

B>>И вообще, я сейчас Оракл не использую, но по старой памяти чего-то не припоминаю "oracle.jdbc.ttc7.TTC7Protocol" — что это за хрень? Может у тебя драйвер очень старый?

vsb>Старый, от 9i, соответствующий базе. Пробовал от 10 когда-то использовать, в некоторых сценариях глюки были, уже не помню какие, в общем решил не экспериментировать.

Разве JDBC драйверы к конкретной базе? Какой у тебя, ojdbc14 (Java 1.4)? Попробуй по нисходящей ojdbc7 (Java 7), ojdbc6, ojdbc5.

Здравствуйте, vsb, Вы писали:

vsb> Я вообще не уверен, что он виноват (не закрывать Statement-ы это не такой большой грех, их закрывает Connection, а раз Connection в пуле, значит этим должен заниматься пул в момент освобождения коннекта, а не когда GC собирает), но мне от этого не легче, оракловые драйверы переписывать я точно не буду
Эээ.. Погоди. Если я ничего не путаю, то собственно суть пула как раз в том, что Connection держится открытым, а не закрывается и отдаётся обратно в пул, для последующего переиспользования.
Т.е. утечка Statement-ов это таки грех.

Здравствуйте, ·, Вы писали:

·>Здравствуйте, vsb, Вы писали:

vsb>> Я вообще не уверен, что он виноват (не закрывать Statement-ы это не такой большой грех, их закрывает Connection, а раз Connection в пуле, значит этим должен заниматься пул в момент освобождения коннекта, а не когда GC собирает), но мне от этого не легче, оракловые драйверы переписывать я точно не буду
·>Эээ.. Погоди. Если я ничего не путаю, то собственно суть пула как раз в том, что Connection держится открытым, а не закрывается и отдаётся обратно в пул, для последующего переиспользования.
·>Т.е. утечка Statement-ов это таки грех.

Да, но у него стэйтмент как раз попал в сборку мусора, а значит не утёк. Просто Оракл какую-то странную конструкцию наворотил с закрытием стэйтментов. Я всё-таки думаю, что это очень старый драйвер.

Здравствуйте, ·, Вы писали:

vsb>> Я вообще не уверен, что он виноват (не закрывать Statement-ы это не такой большой грех, их закрывает Connection, а раз Connection в пуле, значит этим должен заниматься пул в момент освобождения коннекта, а не когда GC собирает), но мне от этого не легче, оракловые драйверы переписывать я точно не буду
·>Эээ.. Погоди. Если я ничего не путаю, то собственно суть пула как раз в том, что Connection держится открытым, а не закрывается и отдаётся обратно в пул, для последующего переиспользования.
·>Т.е. утечка Statement-ов это таки грех.

Наличие пула это вопрос конфигурации приложения. Есть датасорс. То, что это пул, это не моё дело. Я коннект получил, я его закрыл. Если есть гарантия того, что Statement закрывается при закрытии Connection-а, значит пул должен это обеспечивать, причём своевременно. Каких-то проблем это делать я не вижу, пул оборачивает все интерфейсы своими врапперами и ему ничего не мешает отслеживать, какие Statement-ы создавались и закрыть их перед возвращениям соединения в пул. Скорей всего dbcp-шный пул некачественно реализован.

Здравствуйте, bzig, Вы писали:

B>Да, но у него стэйтмент как раз попал в сборку мусора, а значит не утёк. Просто Оракл какую-то странную конструкцию наворотил с закрытием стэйтментов. Я всё-таки думаю, что это очень старый драйвер.

Конечно наличие дедлока выглядит не очень хорошо, но вообще JDBC гарантирует нормальную работу в многопоточном режиме (мне лично непонятно, зачем) и все драйверы обычно тупо фигачат synchronized на все методы, чтобы всё работало нормально. Я не думаю, что в других драйверах что-то отличается. В общем пока пофиксил ту явную утечку statement-ов, посмотрим, поможет ли. Драйвер обновлять это последнее дело, там есть оракл-специфичный код, который годами работал нормально и где что вылезет при замене драйвера, гадать не хочется. Скорее пул поменяю или просто свою обёртку напишу, заодно и увижу, откуда приходят незакрытые коннекты (вот что действительно стоило бы делать dbcp-му пулу, так это логгировать предупреждения о незакрытых объектах).

vsb> Скорее пул поменяю

Причём тут пул? В твоих стэктрэйсах в одном пула вообще нет, в другом пул просто закрытие делегирует. С этим драйвером ты дедлок (возможно) получишь и без файналайзера

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

Как ты себе это представляешь? Пока коннект не вернули, пул считает его использующимся. А возврат в пул как раз для клиента выглядит как close(), при этом коннект не закрывается.

Кстати, в интернете как раз есть обсуждения такой же проблемы и там тоже с LOB связано.

Здравствуйте, bzig, Вы писали:

B>Причём тут пул? В твоих стэктрэйсах в одном пула вообще нет, в другом пул просто закрытие делегирует. С этим драйвером ты дедлок (возможно) получишь и без файналайзера

Один тред абсолютно безобидный. Там идёт вызов метода из MyBatis, который выполняет SQL, который в процессе создаёт CLOB. Моего кода там вообще 1 строчка. А второй тред с финалайзером завязан на пул, который зачем-то решил реализовать finalize. В драйвере оракла finalize я не вижу. Может там какие-нибудь курсоры будут утекать, я хз, раньше такого не происходило.

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

B>Как ты себе это представляешь? Пока коннект не вернули, пул считает его использующимся. А возврат в пул как раз для клиента выглядит как close(), при этом коннект не закрывается.

Хм, я был уверен, что finalize происходит уже после возврата соединения в пул. С другой стороны это не очевидно, да, вполне может быть то, что это исходная транзакция ещё идёт, тогда пул, конечно, закрыть пока ничего не может и я зря на него наезжаю. Хотя всё равно не уверен, что close при finalize уместно в данном случае. Я бы предложил просто держать ссылку в объекте пуле на Statement-ы пока соединение не закрыто, чтобы их сборщик мусора в принципе не мог собрать (конечно при закрытии удалять из списка), а при закрытии соединения уже закрывать все незакрытые раннее Statement-ы.

Здравствуйте, vsb, Вы писали:

vsb>Хм, я был уверен, что finalize происходит уже после возврата соединения в пул.
finalize происходит когда сборщику мусора так захотелось. Притом из специального finalize-треда.

vsb>С другой стороны это не очевидно, да, вполне может быть то, что это исходная транзакция ещё идёт, тогда пул, конечно, закрыть пока ничего не может и я зря на него наезжаю. Хотя всё равно не уверен, что close при finalize уместно в данном случае. Я бы предложил просто держать ссылку в объекте пуле на Statement-ы пока соединение не закрыто, чтобы их сборщик мусора в принципе не мог собрать (конечно при закрытии удалять из списка), а при закрытии соединения уже закрывать все незакрытые раннее Statement-ы.
Соединение в пуле закрывается только во время завершения приложения, при разрушении самого пула. Поэтому если statements где-то забыли закрыть, их приходится финализировать со всевозможными весёлыми спецэффектами, иначе ресурсы тупо кончатся.
Есть имплементации пулов, которые позволяют включить отслеживание незакрытых ресурсов, но оно по дефолту отключено, ибо небесплатно и в нормально написанном приложении не нужно.
Может тебе попробовать что-то такое для поиска утечек?

Здравствуйте, ·, Вы писали:

vsb>>Хм, я был уверен, что finalize происходит уже после возврата соединения в пул.
·>finalize происходит когда сборщику мусора так захотелось. Притом из специального finalize-треда.

Это понятно.

vsb>>С другой стороны это не очевидно, да, вполне может быть то, что это исходная транзакция ещё идёт, тогда пул, конечно, закрыть пока ничего не может и я зря на него наезжаю. Хотя всё равно не уверен, что close при finalize уместно в данном случае. Я бы предложил просто держать ссылку в объекте пуле на Statement-ы пока соединение не закрыто, чтобы их сборщик мусора в принципе не мог собрать (конечно при закрытии удалять из списка), а при закрытии соединения уже закрывать все незакрытые раннее Statement-ы.
·>Соединение в пуле закрывается только во время завершения приложения, при разрушении самого пула.

В данном случае я имел в виду закрытие логического соединения (DelegatingConnection) и возврат физического соединения в пул.

·> Поэтому если statements где-то забыли закрыть, их приходится финализировать со всевозможными весёлыми спецэффектами, иначе ресурсы тупо кончатся.

Если в пределах одной транзакции кто-то не закрывает Statement-ы, пускай кончаются. Это лучше, чем спецэффекты, по крайней мере понять в чём проблема проще. А вообще обычно Statement-ов на транзакцию очень немного, если нужно много записей обработать, делают один PreparedStatement, поэтому это вряд ли будет частой проблемой.

·>Есть имплементации пулов, которые позволяют включить отслеживание незакрытых ресурсов, но оно по дефолту отключено, ибо небесплатно и в нормально написанном приложении не нужно.

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

·>Может тебе попробовать что-то такое для поиска утечек?

Спасибо, если проблема останется, попробую, пока что методом пристального взгляда вроде всё нашлось.

Здравствуйте, vsb, Вы писали:

vsb>·> Поэтому если statements где-то забыли закрыть, их приходится финализировать со всевозможными весёлыми спецэффектами, иначе ресурсы тупо кончатся.
vsb>Если в пределах одной транзакции кто-то не закрывает Statement-ы, пускай кончаются. Это лучше, чем спецэффекты, по крайней мере понять в чём проблема проще.
vsb>А вообще обычно Statement-ов на транзакцию очень немного, если нужно много записей обработать, делают один PreparedStatement, поэтому это вряд ли будет частой проблемой.
"обычно" не достаточно для универсальной jdbc библиотеки, которую могут использовать в хвост и гриву.

vsb>·>Есть имплементации пулов, которые позволяют включить отслеживание незакрытых ресурсов, но оно по дефолту отключено, ибо небесплатно и в нормально написанном приложении не нужно.
vsb>Создавать трейсы может и не бесплатно, а просто держать список незакрытых ресурсов на время транзакции должно быть практически бесплатно, по крайней мере на фоне времени работы БД.
Придётся создавать ещё один слой делегатов практически для всего. Ибо пуловый Connection уже не сможет выдавать родные Statementы и Recordsetы, а должен будет каждый обернуть отдельно для отлова close(), а ещё желательно отслеживать не только тот факт, что что-то не закрылось, но ещё и stacktrace откуда же оно открылось, чтобы сразу найти проблемное место. Т.е. это всё довольно накладно и трейсы включают только на этапах разработки/тестирования.

Здравствуйте, ·, Вы писали:

vsb>>·>Есть имплементации пулов, которые позволяют включить отслеживание незакрытых ресурсов, но оно по дефолту отключено, ибо небесплатно и в нормально написанном приложении не нужно.
vsb>>Создавать трейсы может и не бесплатно, а просто держать список незакрытых ресурсов на время транзакции должно быть практически бесплатно, по крайней мере на фоне времени работы БД.
·>Придётся создавать ещё один слой делегатов практически для всего. Ибо пуловый Connection уже не сможет выдавать родные Statementы и Recordsetы, а должен будет каждый обернуть отдельно для отлова close(), а ещё желательно отслеживать не только тот факт, что что-то не закрылось, но ещё и stacktrace откуда же оно открылось, чтобы сразу найти проблемное место. Т.е. это всё довольно накладно и трейсы включают только на этапах разработки/тестирования.

Так они и так созданы. Финалайзер-то именно оттуда приходит. Насчёт stacktrace не спорю, у меня тоже есть ощущение, что это накладный вызов (хотя это ещё надо потестировать), такое должно быть или за опцией или, в идеале, включаться автоматически после первой обнаруженной утечки, чтобы вторая уже была со стектрейсом.

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


Кидать исключение дорого, а создать исключение и взять стэктрэйс не так дорого, особенно на фоне всяких операций с БД.