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

INFO


Даже если ты никогда не пользовался ни Spring, ни Log4j 2, то после прочтения этой статьи ты все равно получишь довольно четкое представление о том, почему такого рода утечки могут возникать и как с ними бороться.

Хотя эта статья и создана для разработчиков, в ней почти отсутствует программный код: все, что нас будет интересовать, — это конфигурационные файлы. Мы будем наблюдать, как простое подключение новой библиотеки в нашу программу будет приводить к утечкам памяти, а небольшие правки в конфигурации — исправлять их. Впрочем, давай обо всем по порядку.

 

Разговорчивый Spring

Роль Spring Framework при разработке промышленных Java-приложений трудно переоценить. Spring способен в разы сократить объем программного кода, который тебе придется написать и сопровождать, а при умелом использовании — сделать программу простой, понятной и адаптируемой к изменчивым требованиям заказчика.

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

Приведем простой пример. С помощью Spring-WS можно вызывать сторонние SOAP-службы. Ты отправляешь запрос в такую службу, получаешь ответ, выполняешь над ответом какие-нибудь операции и выводишь результат. Пользователь твоей системы смотрит на этот результат и говорит тебе, что он некорректный, а значит, с его точки зрения, твоя программа содержит ошибки.

Возможно, этот пользователь прав. А возможно, ты получил некорректный ответ из сторонней службы. Единственный способ узнать — это чтение логов, которые пишет твоя система. Ты можешь проверить корректность твоего запроса и корректность ответа, который тебе пришел. В случае с SOAP-службами можно выводить в лог XML запросов и ответов. Тогда у тебя будут железные аргументы, что ошибка не на твоей стороне, если это действительно так.

Ты можешь сам написать код, который будет логировать XML-сообщения перед отправкой и после получения ответа. Однако не стоит усложнять свою программу лишней логикой, если Spring-WS уже логирует эти сообщения за тебя. Твоя задача заключается только в том, чтобы перенаправить логи Spring-WS в ту систему логирования, которая используется в программе. Например, в Log4j 2.

Далее я приведу пример простого веб-приложения, которое выводит логи Spring через конфигурацию Log4j 2. При этом будут наблюдаться утечки памяти при остановке и удалении приложения из контейнера сервлетов.

 

Учимся слушать

Создадим пустой проект веб-приложения на основе Apache Maven. Назовем его, например, spring-log4j2-memory-leaks. В нем почти не будет программного кода: нас интересуют только конфигурационные файлы и вывод логов в консоль. Сначала в файле pom.xml объявим только одну зависимость:

<dependencies>
    <dependency>
        <groupId>org.springframework</groupId>
        <artifactId>spring-web</artifactId>
        <version>4.3.3.RELEASE</version>
    </dependency>
</dependencies>

Чтобы Spring инициализировал свой контекст при старте веб-приложения, необходимо зарегистрировать его в дескрипторе развертывания (web.xml):

<?xml version="1.0" encoding="UTF-8"?>
<web-app xmlns="http://xmlns.jcp.org/xml/ns/javaee" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://xmlns.jcp.org/xml/ns/javaee http://xmlns.jcp.org/xml/ns/javaee/webapp_3_1.xsd" version="3.1">
    <listener>
        <listener-class>org.springframework.web.context.ContextLoaderListener</listener-class>
    </listener>
    <context-param>
        <param-name>contextConfigLocation</param-name>
        <param-value>/WEB-INF/spring/applicationContext.xml</param-value>
    </context-param>
</web-app>

Здесь файл applicationContext.xml пуст. Сейчас нам не нужно каким-то особым образом конфигурировать Spring:

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-4.3.xsd">
</beans>

Соберем и опубликуем наше приложение. В этой статье в качестве контейнера сервлетов будет использоваться Apache Tomcat версии 8.0.38. При запуске приложения он выводит в лог сообщения об инициализации контекста Spring:

15-Oct-2016 12:16:03.923 INFO [http-apr-8080-exec-10] org.springframework.web.context.ContextLoader.initWebApplicationContext Root WebApplicationContext: initialization started
15-Oct-2016 12:16:04.303 INFO [http-apr-8080-exec-10] org.springframework.web.context.support.XmlWebApplicationContext.prepareRefresh Refreshing Root WebApplicationContext: startup date [Sat Oct 15 12:16:04 MSK 2016]; root of context hierarchy
15-Oct-2016 12:16:04.493 INFO [http-apr-8080-exec-10] org.springframework.beans.factory.xml.XmlBeanDefinitionReader.loadBeanDefinitions Loading XML bean definitions from ServletContext resource [/WEB-INF/spring/applicationContext.xml]
15-Oct-2016 12:16:04.738 INFO [http-apr-8080-exec-10] org.springframework.web.context.ContextLoader.initWebApplicationContext Root WebApplicationContext: initialization completed in 815 ms

Теперь подключим к проекту Log4j 2:

<dependencies>
    <dependency>
        <groupId>org.springframework</groupId>
        <artifactId>spring-web</artifactId>
        <version>4.3.3.RELEASE</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-web</artifactId>
        <version>2.7</version>
    </dependency>
</dependencies>

Также создадим для него файл с конфигурацией (log4j2.xml):

<?xml version="1.0" encoding="UTF-8" ?>
<Configuration status="debug">
    <Properties>
        <Property name="pattern">[%thread] %d{yyyy-MM-dd HH:mm:ss.SSS} %-5level %c{1} - %msg%n</Property>
    </Properties>
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="${pattern}" />
        </Console>
    </Appenders>
    <Loggers>
        <Root level="trace">
            <AppenderRef ref="Console" />
        </Root>
    </Loggers>
</Configuration>

Как видишь, конфигурация предельно проста: логи Log4j 2 выводятся в консоль в определенном формате.

Теперь если мы опять соберем проект и опубликуем его, то увидим, что в логах появилось большое количество записей об инициализации контекста Log4j 2:

2016-10-15 12:41:32,949 http-apr-8080-exec-29 DEBUG Starting LoggerContext[name=/spring-log4j2-memory-leaks-1.0] from configuration at file:/C:/Program%20Files/apache-tomcat-8.0.38/webapps/spring-log4j2-memory-leaks-1.0/WEB-INF/log4j2.xml
...
2016-10-15 12:41:33,130 http-apr-8080-exec-29 DEBUG LoggerContext[name=/spring-log4j2-memory-leaks-1.0, org.apache.logging.log4j.core.LoggerContext@2e7453a5] started OK with configuration XmlConfiguration[location=C:\Program Files\apache-tomcat-8.0.38\webapps\spring-log4j2-memory-leaks-1.0\WEB-INF\log4j2.xml].

Однако мы все еще не видим логов Spring! Дело в том, что в нем используется Apache Commons Logging, а значит, мы должны подключить в наш проект Commons Logging Bridge для перенаправления логов из Commons Logging в Log4j 2. Для этого необходимо только добавить новую зависимость в проект:

<dependencies>
    <dependency>
        <groupId>org.springframework</groupId>
        <artifactId>spring-web</artifactId>
        <version>4.3.3.RELEASE</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-web</artifactId>
        <version>2.7</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-jcl</artifactId>
        <version>2.7</version>
    </dependency>
</dependencies>

В очередной раз пересоберем и опубликуем проект. Теперь мы можем наблюдать в логах низкоуровневые детали инициализации контекста Spring. Это означает, что Spring-WS из нашего примера в начале статьи также будет выводить в лог XML, которые он отправляет и получает. И не только он. Все библиотеки Spring будут извещать нас о том, что они делают. К примеру, Spring JDBC выведет в лог запросы к БД, Spring AMQP — сообщения из очереди и так далее. В нашем программном коде будет меньше вызовов логгера, а значит, он станет проще.

 

Утечки памяти

На этой оптимистической ноте следовало бы завершить статью, однако настройка нашего веб-приложения еще не закончена. Дело в том, что если мы перезапустим нашу программу, например нажав на кнопку Reload в административной панели Tomcat’а, как показано на рис. 1, то создадим утечку памяти.

Рис. 1. Кнопка Reload
Рис. 1. Кнопка Reload

Ты спросишь, откуда я знаю, что появилась утечка? Есть несколько несложных способов проверить. Самый простой — кнопка Find leaks в административной панели Tomcat’а (рис. 2).

Рис. 2. Кнопка Find leaks
Рис. 2. Кнопка Find leaks

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

Рис. 3. Утечки памяти
Рис. 3. Утечки памяти

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

Неочищенный мусор логгера также можно увидеть в MBean Browser в Oracle Java Mission Control (рис. 4).

Рис. 4. Oracle Java Mission Control
Рис. 4. Oracle Java Mission Control

Еще один способ — с помощью команды jmap -histo [tomcat pid]. В результате ты увидишь множество классов из твоего приложения, которые дублируются столько раз, сколько ты перезапускаешь приложение, плюс то, что сейчас работает (в нашем случае: 3 + 1 = 4). Пример:

2065: 1 24 org.apache.logging.log4j.core.impl.Log4jContextFactory
2066: 1 24 org.apache.logging.log4j.core.impl.Log4jContextFactory
2067: 1 24 org.apache.logging.log4j.core.impl.Log4jContextFactory
2068: 1 24 org.apache.logging.log4j.core.impl.Log4jContextFactory

Можно задать резонный вопрос: а так ли часто мы перезапускаем веб-приложения? Ответ простой: часто. Например, при установке новой версии. Или при изменении конфигурации программы. Если ты захочешь изменить уровень логирования в приложении с debug на info, то ты откроешь *.war-файл и отредактируешь в нем log4j2.xml. Tomcat автоматически подхватит твои изменения и сделает рестарт приложения, что, в свою очередь, вызовет утечку памяти.

Продолжение статьи доступно только подписчикам

Вариант 1. Оформи подписку на «Хакер», чтобы читать все статьи на сайте

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

Вариант 2. Купи одну статью

Заинтересовала статья, но нет возможности оплатить подписку? Тогда этот вариант для тебя! Обрати внимание: этот способ покупки доступен только для статей, опубликованных более двух месяцев назад.


1 комментарий

Подпишитесь на ][, чтобы участвовать в обсуждении

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

Check Also

Espruino Pico. Учимся программировать USB-микроконтроллер на JavaScript и делаем из него токен авторизации

Несмотря на огромное количество устройств на базе микроконтроллеров, созданных на волне ус…