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.

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).

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

>
> 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&amp;characterEncoding=latin5&amp;characterResultSet=latin5&amp;zeroDateTimeBehavior=convertToNull&amp;autoReconnect=true&amp;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

Reply via email to