Пул соединений Tomcat jdbc не обеспечивает выполнение testOnBorrow и / или validationQueryTimeout - PullRequest
0 голосов
/ 05 июля 2018

У меня проблема с пулом соединений jdbc в Tomcat / 7.0.8: похоже, что он не применяет параметры testOnBorrow и / или validationQueryTimeout.


На сервере Tomcat определен следующий ресурс JDBC:

<Resource
  name="jdbc/DataSource"
  auth="Container"
  type="javax.sql.DataSource"
  username="${DB_USERNAME}"
  password="${DB_PASSWORD}"
  maxActive="100"
  maxIdle="0"
  maxWait="10000"
  initialSize="0"
  testOnBorrow="true"
  testOnConnect="true"
  validationQuery="select 1 from dual"
  validationQueryTimeout="5"
  suspectTimeout="600"
  removeAbandoned="true"
  removeAbandonedTimeout="600"
  logAbandoned="true"
  abandonWhenPercentageFull="100"
  timeBetweenEvictionRunsMillis="5000"
  minEvictableIdleTimeMillis="600000"
  validationInterval="3000"

  jdbcInterceptors="StatementCache(prepared=true,callable=false,max=100)"
  factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"
  driverClassName="oracle.jdbc.driver.OracleDriver"
  url="jdbc:oracle:thin:@remote-db-server.domain.com:1521/DB_NAME"
/>

До появления проблем с подключением к базе данных процесс Tomcat открыл 2 подключения к БД:

Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address               Foreign Address             State
tcp        0     93 10.215.221.83:50126         10.215.221.154:1521         ESTABLISHED
tcp        0     92 10.215.221.83:50160         10.215.221.154:1521         ESTABLISHED

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

Я вижу, что те же 2 (больше не работающие) подключения к базе данных остаются открытыми в течение 10-15 минут, даже если база данных больше не отвечает (как вы видите в параметре Send-Q ниже - со значениями 93 и 92 ):

Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address               Foreign Address             State
tcp        0     93 10.215.221.83:50126         10.215.221.154:1521         
ESTABLISHED
tcp        0     92 10.215.221.83:50160         10.215.221.154:1521         ESTABLISHED

Я также вижу в дампе потока 2 потока, которые используют соединения с БД, как показано ниже, и они действительно находятся в socketRead0, ожидая ответа от базы данных:

"http-bio-8543-exec-6" #50 daemon prio=5 os_prio=0 tid=0x00007f3bb06fe000 nid=0x62a5 runnable [0x00007f3b38a13000]
    java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:170)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at oracle.net.ns.Packet.receive(Packet.java:311)
        at oracle.net.ns.DataPacket.receive(DataPacket.java:105)
        at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:305)
        at oracle.net.ns.NetInputStream.read(NetInputStream.java:249)
        at oracle.net.ns.NetInputStream.read(NetInputStream.java:171)
        at oracle.net.ns.NetInputStream.read(NetInputStream.java:89)
        at oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:123)
        at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:79)
        at oracle.jdbc.driver.T4CMAREngineStream.unmarshalUB1(T4CMAREngineStream.java:426)
        at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:390)
        at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:249)
        at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:566)
        at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:202)
        at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:45)
        at oracle.jdbc.driver.T4CStatement.executeForDescribe(T4CStatement.java:766)
        at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:897)
        at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1026)
        at oracle.jdbc.driver.OracleStatement.executeInternal(OracleStatement.java:1718)
        at oracle.jdbc.driver.OracleStatement.execute(OracleStatement.java:1678)
        - locked <0x00000006c3043008> (a oracle.jdbc.driver.T4CConnection)
        at oracle.jdbc.driver.OracleStatementWrapper.execute(OracleStatementWrapper.java:332)
        at org.apache.tomcat.jdbc.pool.PooledConnection.validate(PooledConnection.java:483)
        at org.apache.tomcat.jdbc.pool.PooledConnection.validate(PooledConnection.java:394)
        at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:794)
        at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:648)
        at org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:200)
        at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
        at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:70)
        at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:292)
        at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:214)
        at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:157)
        at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:67)
        at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:160)
        at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1425)
        at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:59)
        at org.springframework.orm.jpa.DefaultJpaDialect.beginTransaction(DefaultJpaDialect.java:67)
        at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:110)
        at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:380)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:420)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:257)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:95)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
        at com.sun.proxy.$Proxy131.getSecurityUserKey(Unknown Source)
        at com.fairisaac.edm.cc.security.audit.impl.SecurityAuditFacadeImpl.auditLogout(SecurityAuditFacadeImpl.java:208)
        at com.fairisaac.edm.cc.security.audit.AuditService.auditLogout(AuditService.java:164)
        at com.fairisaac.edm.cc.security.manager.SecurityManager.logout(SecurityManager.java:573)
        at com.fairisaac.edm.cc.security.authentication.CustomSessionListener.sessionDestroyed(CustomSessionListener.java:63)
        at org.apache.catalina.session.StandardSession.expire(StandardSession.java:800)
        - locked <0x000000077fc73ce0> (a org.apache.catalina.session.StandardSession)
        at org.apache.catalina.session.StandardSession.expire(StandardSession.java:732)
        at org.apache.catalina.session.StandardSession.invalidate(StandardSession.java:1264)
        at org.apache.catalina.session.StandardSessionFacade.invalidate(StandardSessionFacade.java:183)
        at com.fairisaac.edm.fraud.components.LogoutServlet.service(LogoutServlet.java:33)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at com.fairisaac.edm.cc.reporting.LogoutFilter.doFilter(LogoutFilter.java:192)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at com.fairisaac.edm.cc.security.requestvalidator.SecurityFilter.doFilter(SecurityFilter.java:143)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:506)
        at com.fairisaac.edm.cc.security.authentication.tomcat.FFMAuthenticator.invoke(FFMAuthenticator.java:44)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:962)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)
        at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1115)
        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
        at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
        - locked <0x000000077cf30318> (a org.apache.tomcat.util.net.SocketWrapper)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.lang.Thread.run(Thread.java:745)

2 подключения и потоки остаются в одном и том же состоянии около 15 минут, после чего Tomcat наконец регистрирует ошибку и закрывает подключения:

ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] IO Error: The Network Adapter could not establish the connection
ERROR [com.fairisaac.edm.cc.security.manager.SecurityManager] org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is javax.persistence.PersistenceException: org.hibernate.exception.JDBCConnectionException: Could not open connection
com.fairisaac.edm.cc.security.audit.SecuirtyAuditException: org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is javax.persistence.PersistenceException: org.hibernate.exception.JDBCConnectionException: Could not open connection
        at com.fairisaac.edm.cc.security.audit.AuditService.auditLogout(AuditService.java:167)
        at com.fairisaac.edm.cc.security.manager.SecurityManager.logout(SecurityManager.java:573)
        at com.fairisaac.edm.cc.security.authentication.CustomSessionListener.sessionDestroyed(CustomSessionListener.java:63)
        at org.apache.catalina.session.StandardSession.expire(StandardSession.java:800)
        at org.apache.catalina.session.StandardSession.expire(StandardSession.java:732)
        at org.apache.catalina.session.StandardSession.invalidate(StandardSession.java:1264)
        at org.apache.catalina.session.StandardSessionFacade.invalidate(StandardSessionFacade.java:183)
        at com.fairisaac.edm.fraud.components.LogoutServlet.service(LogoutServlet.java:33)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at com.fairisaac.edm.cc.reporting.LogoutFilter.doFilter(LogoutFilter.java:192)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at com.fairisaac.edm.cc.security.requestvalidator.SecurityFilter.doFilter(SecurityFilter.java:143)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:506)
        at com.fairisaac.edm.cc.security.authentication.tomcat.FFMAuthenticator.invoke(FFMAuthenticator.java:44)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:962)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)
        at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1115)
        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
        at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.lang.Thread.run(Thread.java:745)
Caused by: org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is javax.persistence.PersistenceException: org.hibernate.exception.JDBCConnectionException: Could not open connection
        at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:430)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:420)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:257)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:95)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
        at com.sun.proxy.$Proxy131.getSecurityUserKey(Unknown Source)
        at com.fairisaac.edm.cc.security.audit.impl.SecurityAuditFacadeImpl.auditLogout(SecurityAuditFacadeImpl.java:208)
        at com.fairisaac.edm.cc.security.audit.AuditService.auditLogout(AuditService.java:164)
        ... 35 more
Caused by: javax.persistence.PersistenceException: org.hibernate.exception.JDBCConnectionException: Could not open connection
        at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1387)
        at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1310)
        at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:1397)
        at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:62)
        at org.springframework.orm.jpa.DefaultJpaDialect.beginTransaction(DefaultJpaDialect.java:67)
        at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:110)
        at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:380)
        ... 44 more
Caused by: org.hibernate.exception.JDBCConnectionException: Could not open connection
        at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:131)
        at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110)
        at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:221)
        at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:157)
        at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:67)
        at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:160)
        at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1425)
        at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:59)
        ... 47 more
Caused by: java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection
        at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:673)
        at oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:715)
        at oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:385)
        at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:30)
        at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:564)
        at org.apache.tomcat.jdbc.pool.PooledConnection.connectUsingDriver(PooledConnection.java:278)
        at org.apache.tomcat.jdbc.pool.PooledConnection.connect(PooledConnection.java:182)
        at org.apache.tomcat.jdbc.pool.PooledConnection.reconnect(PooledConnection.java:315)
        at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:813)
        at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:648)
        at org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:200)
        at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
        at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:70)
        at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:292)
        at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:214)
        ... 52 more
Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection
        at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:445)
        at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:464)
        at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:594)
        at oracle.net.ns.NSProtocol.connect(NSProtocol.java:229)
        at oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1360)
        at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:486)
        ... 66 more
Caused by: java.net.NoRouteToHostException: No route to host
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
        at java.net.Socket.connect(Socket.java:589)
        at oracle.net.nt.TcpNTAdapter.connect(TcpNTAdapter.java:162)
        at oracle.net.nt.ConnOption.connect(ConnOption.java:133)
        at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:411)
        ... 71 more

Так что мне кажется, что настройки testOnBorrow и / или validationQueryTimeout не применяются пулом соединений.

...