Началось все с нерегулярных обращений от пользователей о зависании веб-приложения, которое выражалось в том, что после ввода имени пользователя и пароля веб-страница зависала, а именно, переходила в режим "вечного ожидания ответа от веб-сервера".
Единственной полезной зацепкой была ошибка в "catalina.out" (лог-файл веб-сервера Apache Tomcat 9, при чем не сразу стало понятно, что указанная ниже информация записывается туда, при штатных настройках Apache Tomcat, только после остановки веб-сервера или после остановки проблемного веб-приложения, например, в "Tomcat Manager Application"):
19-Sep-2020 08:26:57.691 WARNING [http-nio-8080-exec-914] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [jenki##2.1.28] is still processing a request that has yet to finish. This is very likely to create a memory leak. You can control the time allowed for requests to finish by using the unloadDelay attribute of the standard Context implementation. Stack trace of request processing thread:[Последние две строки дали мне, как автору веб-приложения, понять, что проблема возникла, когда пользователь ввел пароль и началось ожидание подключения к БД для загрузки данных, которые пользователь ожидает на экране своего интернет-браузера. Таким образом, это дало уверенность в том, что на найденную ошибку можно спокойно опереться при дальнейшем анализе.
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
org.apache.tomcat.dbcp.pool2.impl.LinkedBlockingDeque.takeFirst(LinkedBlockingDeque.java:586)
org.apache.tomcat.dbcp.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:438)
org.apache.tomcat.dbcp.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:359)
org.apache.tomcat.dbcp.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:134)
org.apache.tomcat.dbcp.dbcp2.BasicDataSource.getConnection(BasicDataSource.java:1543)
com.jenki.multicon.AppContextReader.<init>(AppContextReader.java:14)
com.jenki.LoginServlet.doPost(LoginServlet.java:46)
...
Поиск по остальным строкам стека ошибки привел к подобного рода обсуждениям: https://github.com/dotCMS/core/issues/7790 - тут описываются нюансы настройки подключений к БД через "context.xml" Томката (как раз, мой случай) с использованием параметров:
maxActive="60" maxIdle="10" maxWait="60000" removeAbandoned="true" removeAbandonedTimeout="60" logAbandoned="true" validationQuery="SELECT 1" testOnBorrow="true"После попытки применения указанных на странице по ссылке параметров "maxActive", "maxWait" Томкат при запуске в своей консоли сообщает о том, что эти параметры для "фабрики пула соединений" устарели и вместо них нужно использовать актуальные, соответственно, "maxTotal" (по умолчанию "8" - Привет, зависания после 8 обновлений веб-страницы!), "maxWaitMillis" (по умолчанию "-1"). Там же Томкат сообщает наименование текущей фабрики подключений - "org.apache.tomcat.dbcp.dbcp2.BasicDataSourceFactory" - оказывается, эта фабрика запускается Томкатом 9 автоматически, если администратор в context.xml в блоке настроек для подключения к БД не указывает другую фабрику с помощью тэга "factory" (описано в https://tomcat.apache.org/tomcat-9.0-doc/config/context.html#Resource_Definitions).
Поиск дополнительной информации на тему зависаний веб-приложения после 8 подключений к БД приводит к совету https://stackoverflow.com/questions/30879706/why-does-my-tomcat-only-open-8-jdbc-connections об использовании «factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"».
В итоге, блок настройки подключений к БД веб-приложения выглядит следующим образом:
<Resource name="jdbc/jenki"
auth="Container"
driverClassName="oracle.jdbc.driver.OracleDriver"
url="jdbc:oracle:thin:@myserver:1521:db"
username="mySYSDBA"
password="mypassw"
type="javax.sql.DataSource"
factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"
maxActive="100" maxIdle="30" maxWait="10000"
removeAbandoned="true" removeAbandonedTimeout="40" logAbandoned="true" testOnBorrow="true" />
Теперь в логе Томката (catalina.out) видны лишь строки, символизирующие закрытие подключений (позднее будет проведена проверка кода приложения - возможно, подключения не всегда корректно закрываются, но пока с этим справляется "Tomcat JDBC Pool Cleaner"):
23-Sep-2020 12:27:26.355 WARNING [Tomcat JDBC Pool Cleaner[2129789493:1600853171352]] org.apache.tomcat.jdbc.pool.ConnectionPool.abandon Connection has been abandoned PooledConnection[oracle.jdbc.driver.T4CConnection@3af0c98d]:java.lang.Exception...23-Sep-2020 12:52:51.415 WARNING [Tomcat JDBC Pool Cleaner[2129789493:1600853171352]] org.apache.tomcat.jdbc.pool.ConnectionPool.abandon Connection has been abandoned PooledConnection[oracle.jdbc.driver.T4CConnection@6ea26def]:java.lang.Exception...23-Sep-2020 14:02:51.570 WARNING [Tomcat JDBC Pool Cleaner[2129789493:1600853171352]] org.apache.tomcat.jdbc.pool.ConnectionPool.abandon Connection has been abandoned PooledConnection[oracle.jdbc.driver.T4CConnection@41e58b1f]:java.lang.Exception...23-Sep-2020 14:04:26.574 WARNING [Tomcat JDBC Pool Cleaner[2129789493:1600853171352]] org.apache.tomcat.jdbc.pool.ConnectionPool.abandon Connection has been abandoned PooledConnection[oracle.jdbc.driver.T4CConnection@338e76fa]:java.lang.Exception...23-Sep-2020 14:52:16.686 WARNING [Tomcat JDBC Pool Cleaner[2129789493:1600853171352]] org.apache.tomcat.jdbc.pool.ConnectionPool.abandon Connection has been abandoned PooledConnection[oracle.jdbc.driver.T4CConnection@2165cd9c]:java.lang.Exception
===========================
Порядок действий для стабильного повторения:1. Открываем несколько разных сессий к веб-приложению (можно даже под одним и тем же пользователем, главное, чтобы это были разные сессии), для этого нужно, к примеру, если тестируется на одном компьютере, то можно открыть 6 окон в 3-х разных браузерах (к примеру, Яндекс.Браузер, Firefox, Chrome): 3 окна в штатном режиме и 3 окна в приватном;
2. Несколько раз (около 6 в каждом окне по очереди) обновляем страницу;
3. Ждем около 20-30 минут (окна браузеров не закрываем);
4. Повторяем пункт 2.
Ожидаемый результат (до исправления):
обновление страницы будет выполнено штатно, пользователь увидит данные на обновленной странице.
Фактический результат (до исправления):
Примерно 4 из 6 окон перейдут в режим ожидания ответа от веб-сервера.
Результат тестирования после примененного исправления ...
Комментариев нет:
Отправить комментарий