Dear Phil , Thanks for your feedback. I forgot to mention the mysql driver version. The Mysql driver version is 5.1.32. My plan is to upgrade the mysql driver to 5.1.46 version and monitor for a while.
On Sat, Aug 29, 2020 at 6:50 PM Phil Steitz <phil.ste...@gmail.com> wrote: > > 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 > > -- Gokhan Akgul Best regards
