On 8/27/20 2:47 AM, Gokhan Akgul wrote:
Hi ,
I have been facing the deadlock issue for the last 2 months about
JDBCPoolCleaner Thread .
Following config set in context.xml
<Resource name="jdbc/database"
auth="Container"
type="javax.sql.DataSource"
factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"
driverClassName="com.mysql.jdbc.Driver"
url="jdbc:mysql://adress:3306/db?useUnicode=true&characterEncoding=latin5&characterResultSet=latin5&zeroDateTimeBehavior=convertToNull&autoReconnect=true&interactiveClient=true"
username="user"
password="pass"
initialSize="10"
maxActive="30"
maxIdle="15"
minIdle="10"
maxWait="30000"
timeBetweenEvictionRunsMillis="5000"
minEvictableIdleTimeMillis="60000"
removeAbandonedTimeout="600"
removeAbandoned="true"
logAbandoned="false"
testWhileIdle="true"
testOnBorrow="true"
testOnReturn="false"
validationQuery="/* ping */ SELECT 1"
validationInterval="30000"
jmxEnabled="true"
jdbcInterceptors="ConnectionState;StatementFinalizer;ResetAbandonedTimer;SlowQueryReport"
/>
Thread dump
Tomcat JDBC Pool Cleaner[63445188:1598345711425] id=16 state=BLOCKED
- waiting to lock <0x57dcb0b7> (a com.mysql.jdbc.JDBC4PreparedStatement)
owned by http-nio-8080-exec-8 id=25
at com.mysql.jdbc.PreparedStatement.realClose(PreparedStatement.java:3078)
at
com.mysql.jdbc.ConnectionImpl.closeAllOpenStatements(ConnectionImpl.java:1584)
at com.mysql.jdbc.ConnectionImpl.realClose(ConnectionImpl.java:4364)
at com.mysql.jdbc.ConnectionImpl.close(ConnectionImpl.java:1556)
at
org.apache.tomcat.jdbc.pool.PooledConnection.disconnect(PooledConnection.java:388)
at
org.apache.tomcat.jdbc.pool.PooledConnection.release(PooledConnection.java:618)
at
org.apache.tomcat.jdbc.pool.ConnectionPool.release(ConnectionPool.java:612)
at
org.apache.tomcat.jdbc.pool.ConnectionPool.abandon(ConnectionPool.java:569)
at
org.apache.tomcat.jdbc.pool.ConnectionPool.checkAbandoned(ConnectionPool.java:999)
at
org.apache.tomcat.jdbc.pool.ConnectionPool$PoolCleaner.run(ConnectionPool.java:1468)
at java.util.TimerThread.mainLoop(Timer.java:555)
at java.util.TimerThread.run(Timer.java:505)
Locked synchronizers: count = 1
- java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync@58039868
http-nio-8080-exec-8 id=25 state=BLOCKED
- waiting to lock <0x42de9995> (a com.mysql.jdbc.JDBC4Connection)
owned by Tomcat JDBC Pool Cleaner[63445188:1598345711425] id=16
at
com.mysql.jdbc.ConnectionImpl.useAnsiQuotedIdentifiers(ConnectionImpl.java:5435)
at
com.mysql.jdbc.DatabaseMetaData.getIdentifierQuoteString(DatabaseMetaData.java:3269)
at com.mysql.jdbc.DatabaseMetaData.<init>(DatabaseMetaData.java:675)
at
com.mysql.jdbc.JDBC4DatabaseMetaData.<init>(JDBC4DatabaseMetaData.java:39)
at sun.reflect.GeneratedConstructorAccessor24.newInstance(Unknown Source)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.DatabaseMetaData.getInstance(DatabaseMetaData.java:657)
at com.mysql.jdbc.ConnectionImpl.getMetaData(ConnectionImpl.java:3064)
at com.mysql.jdbc.ConnectionImpl.getMetaData(ConnectionImpl.java:3056)
at
com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2315)
at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.apache.tomcat.jdbc.pool.interceptor.AbstractQueryReport$StatementProxy.invoke(AbstractQueryReport.java:210)
at com.sun.proxy.$Proxy44.executeQuery(Unknown Source)
at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.apache.tomcat.jdbc.pool.interceptor.AbstractQueryReport$StatementProxy.invoke(AbstractQueryReport.java:210)
at com.sun.proxy.$Proxy44.executeQuery(Unknown Source)
at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.apache.tomcat.jdbc.pool.StatementFacade$StatementProxy.invoke(StatementFacade.java:114)
at com.sun.proxy.$Proxy44.executeQuery(Unknown Source)
at
org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:208)
at org.hibernate.loader.Loader.getResultSet(Loader.java:1953)
at org.hibernate.loader.Loader.doQuery(Loader.java:802)
at
org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:274)
at org.hibernate.loader.Loader.doList(Loader.java:2542)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2276)
at org.hibernate.loader.Loader.list(Loader.java:2271)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:459)
at
org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:365)
at
org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:196)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1268)
at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:246)
......
at
com.gg.healthcheck.servlet.HealthCheckServlet.getServiceStatus(HealthCheckServlet.java:68)
at
com.gg.healthcheck.servlet.HealthCheckServlet.doGet(HealthCheckServlet.java:45)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:626)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:733)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at
org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
at
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:543)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
at
org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:690)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
at
org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:615)
at
org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:818)
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1626)
at
org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
- locked org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@526aa725
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
Locked synchronizers: count = 1
- java.util.concurrent.ThreadPoolExecutor$Worker@21c6b5b9
It looks to me like the deadlock is caused by inconsistent lock
acquisition order by the JDBC driver. The driver locks the connection
in the cleaner's close method, but when cleaning up open statements it
needs the lock on a statement. The application thread first acquires
the statement lock but then needs the connection lock. The result is a
deadlock.
See the discussion of this mysql driver bug:
https://bugs.mysql.com/bug.php?id=64954
There is a comment there about the locking model being changed in a
later version of the driver, so you might try upgrading to the latest
driver compatible with your jdk and tomcat version.
Phil
Tomcat version : 8.8.57
Java 7
Application is a simple spring mvc application.
Runs on Kubernetes
Do you have any idea how to solve it?
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
