Am 31.08.20 um 18:53 schrieb Phil Steitz: > > On 8/31/20 3:21 AM, Felix Schumacher wrote: >> Am 31.08.20 um 06:15 schrieb Gokhan Akgul: >>> 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. >> If I read the bug report correctly, MySQL will not change its logic and >> therefore using newer versions of the driver will not help. > > Yeah. There was a comment in another related bug report about > changing the locking model in 5.1.x, so it is possible a later version > will help, but you are right that it probably won't. > >> >> What MySQL advises is to change the pool to use the abort-Method of the >> connection to close it in the case of abandoned connections. >> >> The dbcp2 pools seems to be able to use that method, while I found no >> reference to it in the jdbc-pool module (which you are using). > > We are talking about making that change on commons-dev now [1], but > currently dbcp2 uses close as jdbc-pool does.
You are of course right, I just grepped the sources for abort and skimmed the comments. Should have looked more closely. Felix > > Comments / patches welcome! > > Phil > >> >> So, maybe it is a good idea to switch the used pool from the jdbc-pool >> to the default tomcat pool (see >> http://tomcat.apache.org/tomcat-9.0-doc/jndi-datasource-examples-howto.html). >> >> It should work equally well (I am not sure, if it supports something >> like the slowqueryreport, though). If you want to continue using the old >> jdbc-pool module, you might want to file a bug on the bugtracker asking >> for an enhancement to support the abort method. (I would use the dbcp2 >> pool.) >> >> Felix > > > [1] > https://lists.apache.org/thread.html/r598c0f654477372d112858af1c18bfc04008250156989647d883576f%40%3Cdev.commons.apache.org%3E > >> >>> 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 >>>> >>>> >> --------------------------------------------------------------------- >> To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org >> For additional commands, e-mail: users-h...@tomcat.apache.org >> > > --------------------------------------------------------------------- > To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org > For additional commands, e-mail: users-h...@tomcat.apache.org > --------------------------------------------------------------------- To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
