Tomcat JDBC Pool Cleaner Deadlock Problem

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
11 messages Options
Reply | Threaded
Open this post in threaded view
|

Tomcat JDBC Pool Cleaner Deadlock Problem

Gökhan
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





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?

--
Gokhan Akgul
Best regards
Reply | Threaded
Open this post in threaded view
|

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

Christopher Schultz-2
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Gokhan,

On 8/27/20 05:47, 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=convertTo
Null&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;ResetAbandonedTim
er;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(PooledConnecti
on.java:388)
>
>
at
org.apache.tomcat.jdbc.pool.PooledConnection.release(PooledConnection.ja
va:618)
> at
> org.apache.tomcat.jdbc.pool.ConnectionPool.release(ConnectionPool.java
:612)
>
>
at
org.apache.tomcat.jdbc.pool.ConnectionPool.abandon(ConnectionPool.java:5
69)
> at
> org.apache.tomcat.jdbc.pool.ConnectionPool.checkAbandoned(ConnectionPo
ol.java:999)
>
>
at
org.apache.tomcat.jdbc.pool.ConnectionPool$PoolCleaner.run(ConnectionPoo
l.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(DatabaseMetaDat
a.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(DelegatingCo
nstructorAccessorImpl.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:231
5)
> at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source) at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccess
orImpl.java:43)
>
>
at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.apache.tomcat.jdbc.pool.interceptor.AbstractQueryReport$StatementP
roxy.invoke(AbstractQueryReport.java:210)
>
>
at com.sun.proxy.$Proxy44.executeQuery(Unknown Source)
> at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source) at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccess
orImpl.java:43)
>
>
at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.apache.tomcat.jdbc.pool.interceptor.AbstractQueryReport$StatementP
roxy.invoke(AbstractQueryReport.java:210)
>
>
at com.sun.proxy.$Proxy44.executeQuery(Unknown Source)
> at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source) at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccess
orImpl.java:43)
>
>
at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.apache.tomcat.jdbc.pool.StatementFacade$StatementProxy.invoke(Stat
ementFacade.java:114)
>
>
at com.sun.proxy.$Proxy44.executeQuery(Unknown Source)
> at
> org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:2
08)
>
>
at org.hibernate.loader.Loader.getResultSet(Loader.java:1953)
> at org.hibernate.loader.Loader.doQuery(Loader.java:802) at
> org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loa
der.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.jav
a:365)
>
>
at
org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:19
6)
> 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(HealthC
heckServlet.java:68)
>
>
at
com.gg.healthcheck.servlet.HealthCheckServlet.doGet(HealthCheckServlet.j
ava: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(Appli
cationFilterChain.java:231)
>
>
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilt
erChain.java:166)
> at
> org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
>
>
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Applica
tionFilterChain.java:193)
> at
> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFi
lterChain.java:166)
>
>
at
org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(
CharacterEncodingFilter.java:88)
> at
> org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRe
questFilter.java:107)
>
>
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Applica
tionFilterChain.java:193)
> at
> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFi
lterChain.java:166)
>
>
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValv
e.java:199)
> at
> org.apache.catalina.core.StandardContextValve.invoke(StandardContextVa
lve.java:96)
>
>
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(Authenticator
Base.java:543)
> at
> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.ja
va:139)
>
>
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java
:81)
> at
> org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAcces
sLogValve.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:61
5)
> at
> org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLigh
t.java:65)
>
>
at
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractPro
tocol.java:818)
> at
> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoi
nt.java:1626)
>
>
at
org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.j
ava:49)
> - locked
> org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@526aa725 at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.j
ava:1145)
>
>
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
va:615)
> at
> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThr
ead.java:61)
>
>
at java.lang.Thread.run(Thread.java:745)

>
> Locked synchronizers: count = 1 -
> java.util.concurrent.ThreadPoolExecutor$Worker@21c6b5b9
>
>
>
>
>
> 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?

What makes you think there is deadlock here?

- -chris
-----BEGIN PGP SIGNATURE-----
Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/

iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl9H8P0ACgkQHPApP6U8
pFgXJA//aP2tqTjJiYz+SqwwH8V8Ad/HoP78ucJe0sCC6C8WeGjulIsSZ/Wouxmv
YyReEoCTCwuIaIDWJDrbZVyHutZdkWeQFrs/v+sk/AsTiBHFSYtXxtZoDihy5Qt7
vAOXDpC3Oplo19g8hqreDLZsKaSIBJPBAgdI229OvqCgDfAjbqqoMQDLDyQPZqdP
Y+1WJ+4Alge9C1SVoVYFECl4gh+sdVJIwx+hqkBcyztzgEOuJmCyL3jHx7WP5v7t
leEQxY6yikaWqqWjo69rHNtTwJYgkr39Uhr7EgvrXcxSdAze6Suzt8NxdirXDA6z
hnjVAONXxgx4Mu8XDu0OPgwjfLHkYJqEqxlfKuZ28LMTX4rdJU4aVCB3skSHPGEy
B15EapoVJBbdxT5hTlWr6dAzj8Lt8Nrda6qt4HWpJBvxvikek1MsamYrkOkeGkiW
SiHGxV0KetvIC1S1lwbh0n01tt/Jzunm9RTGa3IBM4V7NotfXk4JHAUU47LDSbD+
qX2k+m/dSuFmjLxE1UM4UBLm0LV7Njp6l0oEezx6be1BjnRLB376LlJjtEwIJjgr
5QMjEPz1Gfey/72gDipaQQEsO5lZmO3u1ThJUnKOboX3QQgJMi6dBGxZmo87JaaO
jE0I1ABApjEWOQclv7Pe3k4ckCFzc7asEDXp7PWZdnVE7NrvnhM=
=WV5I
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

Michael Ng
I had a similar issue with JDBC and it got fixed by adding this
parameter   'numTestsPerEvictionRun'        => '3',

            'auth'                          => 'Container',
            'driverClassName'               => 'oracle.jdbc.OracleDriver',
            'maxActive'                     => '30',
            'maxIdle'                       => '8',
            'maxWait'                       => '-1',
            'minIdle'                       => '1',
            'factory'                       =>
'org.apache.tomcat.jdbc.pool.DataSourceFactory',
            'testWhileIdle'                 => 'true',
            'testOnReturn'                  => 'false',
            'validationQuery'               => 'SELECT 1 FROM DUAL',
            'testOnBorrow'                  => 'true',
            'maxWait'                       => '-1',
            'initialSize'                   => '1',
            'removeAbandoned'               => 'true',
            'logAbandoned'                  => 'true',
            'jmxEnabled'                    => 'true',
            'jdbcInterceptors'              =>
'org.apache.tomcat.jdbc.pool.interceptor.ConnectionState;org.apache.tomcat.jdbc.pool.interceptor.StatementFinalizer',
            'validationInterval'            => '30000',
            'timeBetweenEvictionRunsMillis' => '30000',
            'minEvictableIdleTimeMillis'    => '30000',
            'removeAbandonedTimeout'        => '60',
            'numTestsPerEvictionRun'        => '3',

On Thu, Aug 27, 2020 at 1:44 PM Christopher Schultz
<[hidden email]> wrote:

>
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
>
> Gokhan,
>
> On 8/27/20 05:47, 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=convertTo
> Null&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;ResetAbandonedTim
> er;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(PooledConnecti
> on.java:388)
> >
> >
> at
> org.apache.tomcat.jdbc.pool.PooledConnection.release(PooledConnection.ja
> va:618)
> > at
> > org.apache.tomcat.jdbc.pool.ConnectionPool.release(ConnectionPool.java
> :612)
> >
> >
> at
> org.apache.tomcat.jdbc.pool.ConnectionPool.abandon(ConnectionPool.java:5
> 69)
> > at
> > org.apache.tomcat.jdbc.pool.ConnectionPool.checkAbandoned(ConnectionPo
> ol.java:999)
> >
> >
> at
> org.apache.tomcat.jdbc.pool.ConnectionPool$PoolCleaner.run(ConnectionPoo
> l.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(DatabaseMetaDat
> a.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(DelegatingCo
> nstructorAccessorImpl.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:231
> 5)
> > at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source) at
> > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccess
> orImpl.java:43)
> >
> >
> at java.lang.reflect.Method.invoke(Method.java:606)
> > at
> > org.apache.tomcat.jdbc.pool.interceptor.AbstractQueryReport$StatementP
> roxy.invoke(AbstractQueryReport.java:210)
> >
> >
> at com.sun.proxy.$Proxy44.executeQuery(Unknown Source)
> > at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source) at
> > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccess
> orImpl.java:43)
> >
> >
> at java.lang.reflect.Method.invoke(Method.java:606)
> > at
> > org.apache.tomcat.jdbc.pool.interceptor.AbstractQueryReport$StatementP
> roxy.invoke(AbstractQueryReport.java:210)
> >
> >
> at com.sun.proxy.$Proxy44.executeQuery(Unknown Source)
> > at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source) at
> > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccess
> orImpl.java:43)
> >
> >
> at java.lang.reflect.Method.invoke(Method.java:606)
> > at
> > org.apache.tomcat.jdbc.pool.StatementFacade$StatementProxy.invoke(Stat
> ementFacade.java:114)
> >
> >
> at com.sun.proxy.$Proxy44.executeQuery(Unknown Source)
> > at
> > org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:2
> 08)
> >
> >
> at org.hibernate.loader.Loader.getResultSet(Loader.java:1953)
> > at org.hibernate.loader.Loader.doQuery(Loader.java:802) at
> > org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loa
> der.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.jav
> a:365)
> >
> >
> at
> org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:19
> 6)
> > 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(HealthC
> heckServlet.java:68)
> >
> >
> at
> com.gg.healthcheck.servlet.HealthCheckServlet.doGet(HealthCheckServlet.j
> ava: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(Appli
> cationFilterChain.java:231)
> >
> >
> at
> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilt
> erChain.java:166)
> > at
> > org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
> >
> >
> at
> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Applica
> tionFilterChain.java:193)
> > at
> > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFi
> lterChain.java:166)
> >
> >
> at
> org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(
> CharacterEncodingFilter.java:88)
> > at
> > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRe
> questFilter.java:107)
> >
> >
> at
> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Applica
> tionFilterChain.java:193)
> > at
> > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFi
> lterChain.java:166)
> >
> >
> at
> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValv
> e.java:199)
> > at
> > org.apache.catalina.core.StandardContextValve.invoke(StandardContextVa
> lve.java:96)
> >
> >
> at
> org.apache.catalina.authenticator.AuthenticatorBase.invoke(Authenticator
> Base.java:543)
> > at
> > org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.ja
> va:139)
> >
> >
> at
> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java
> :81)
> > at
> > org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAcces
> sLogValve.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:61
> 5)
> > at
> > org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLigh
> t.java:65)
> >
> >
> at
> org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractPro
> tocol.java:818)
> > at
> > org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoi
> nt.java:1626)
> >
> >
> at
> org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.j
> ava:49)
> > - locked
> > org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@526aa725 at
> > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.j
> ava:1145)
> >
> >
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
> va:615)
> > at
> > org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThr
> ead.java:61)
> >
> >
> at java.lang.Thread.run(Thread.java:745)
> >
> > Locked synchronizers: count = 1 -
> > java.util.concurrent.ThreadPoolExecutor$Worker@21c6b5b9
> >
> >
> >
> >
> >
> > 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?
>
> What makes you think there is deadlock here?
>
> - -chris
> -----BEGIN PGP SIGNATURE-----
> Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/
>
> iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl9H8P0ACgkQHPApP6U8
> pFgXJA//aP2tqTjJiYz+SqwwH8V8Ad/HoP78ucJe0sCC6C8WeGjulIsSZ/Wouxmv
> YyReEoCTCwuIaIDWJDrbZVyHutZdkWeQFrs/v+sk/AsTiBHFSYtXxtZoDihy5Qt7
> vAOXDpC3Oplo19g8hqreDLZsKaSIBJPBAgdI229OvqCgDfAjbqqoMQDLDyQPZqdP
> Y+1WJ+4Alge9C1SVoVYFECl4gh+sdVJIwx+hqkBcyztzgEOuJmCyL3jHx7WP5v7t
> leEQxY6yikaWqqWjo69rHNtTwJYgkr39Uhr7EgvrXcxSdAze6Suzt8NxdirXDA6z
> hnjVAONXxgx4Mu8XDu0OPgwjfLHkYJqEqxlfKuZ28LMTX4rdJU4aVCB3skSHPGEy
> B15EapoVJBbdxT5hTlWr6dAzj8Lt8Nrda6qt4HWpJBvxvikek1MsamYrkOkeGkiW
> SiHGxV0KetvIC1S1lwbh0n01tt/Jzunm9RTGa3IBM4V7NotfXk4JHAUU47LDSbD+
> qX2k+m/dSuFmjLxE1UM4UBLm0LV7Njp6l0oEezx6be1BjnRLB376LlJjtEwIJjgr
> 5QMjEPz1Gfey/72gDipaQQEsO5lZmO3u1ThJUnKOboX3QQgJMi6dBGxZmo87JaaO
> jE0I1ABApjEWOQclv7Pe3k4ckCFzc7asEDXp7PWZdnVE7NrvnhM=
> =WV5I
> -----END PGP SIGNATURE-----
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

Felix Schumacher
In reply to this post by Gökhan

Am 27.08.20 um 11:47 schrieb Gokhan Akgul:

> 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

So, Tomcat tries to close a connection, that it thinks is abandoned
(i.e. in your setup hasn't been used for more than 600 seconds and the
pool of idle connections is getting empty).

The connection is still in use ...

>     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

... by hibernate. The question now is, how often is your healtheck
getting called (every 10 min == 600s)?

If they are close together, you might want to set the abandoned timeout
higher than the healthcheck interval, or you could try to close the
connection (or whatever the equivalent is in hibernate (a session?)) in
your code.

Felix

>     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
>
>
>
>
>
> 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: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

Phil Steitz
In reply to this post by Gökhan

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: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

Gökhan
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 <[hidden email]> 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: [hidden email]
> For additional commands, e-mail: [hidden email]
>
>

--
Gokhan Akgul
Best regards
Reply | Threaded
Open this post in threaded view
|

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

Gökhan
In reply to this post by Felix Schumacher
Dear Felix,

Thanks for your feedback , the health check period is so aggressive now.
SRE team's and apm monitor tools call internally and externally endpoint
and health indicators.
I asked the sre guys to decrease the frequency of those calls. They made
some decrease on calls but nothing changed.
Due to an old spring mvc project it doesn't have a kubernetes probe , about
100 calls in minutes.

Gökhan

On Thu, Aug 27, 2020 at 9:48 PM Felix Schumacher <
[hidden email]> wrote:

>
> Am 27.08.20 um 11:47 schrieb Gokhan Akgul:
> > 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
>
> So, Tomcat tries to close a connection, that it thinks is abandoned
> (i.e. in your setup hasn't been used for more than 600 seconds and the
> pool of idle connections is getting empty).
>
> The connection is still in use ...
>
> >     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
>
> ... by hibernate. The question now is, how often is your healtheck
> getting called (every 10 min == 600s)?
>
> If they are close together, you might want to set the abandoned timeout
> higher than the healthcheck interval, or you could try to close the
> connection (or whatever the equivalent is in hibernate (a session?)) in
> your code.
>
> Felix
>
> >     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
> >
> >
> >
> >
> >
> > 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: [hidden email]
> For additional commands, e-mail: [hidden email]
>
>

--
Gokhan Akgul
Best regards
Reply | Threaded
Open this post in threaded view
|

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

Felix Schumacher

Am 31.08.20 um 06:26 schrieb Gokhan Akgul:
> Dear Felix,
>
> Thanks for your feedback , the health check period is so aggressive now.
> SRE team's and apm monitor tools call internally and externally endpoint
> and health indicators.
> I asked the sre guys to decrease the frequency of those calls. They made
> some decrease on calls but nothing changed.
No, don't decrease the frequency. I meant to have the calls happen more
often than every ten minutes.
> Due to an old spring mvc project it doesn't have a kubernetes probe , about
> 100 calls in minutes.

Those calls have to use the connection, that the health check is using.

Maybe you could check, whether the healtcheck is releasing its
connection back to the pool after it has done its work.

Felix

>
> Gökhan
>
> On Thu, Aug 27, 2020 at 9:48 PM Felix Schumacher <
> [hidden email]> wrote:
>
>> Am 27.08.20 um 11:47 schrieb Gokhan Akgul:
>>> 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
>> So, Tomcat tries to close a connection, that it thinks is abandoned
>> (i.e. in your setup hasn't been used for more than 600 seconds and the
>> pool of idle connections is getting empty).
>>
>> The connection is still in use ...
>>
>>>     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
>> ... by hibernate. The question now is, how often is your healtheck
>> getting called (every 10 min == 600s)?
>>
>> If they are close together, you might want to set the abandoned timeout
>> higher than the healthcheck interval, or you could try to close the
>> connection (or whatever the equivalent is in hibernate (a session?)) in
>> your code.
>>
>> Felix
>>
>>>     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
>>>
>>>
>>>
>>>
>>>
>>> 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: [hidden email]
>> For additional commands, e-mail: [hidden email]
>>
>>

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

Felix Schumacher
In reply to this post by Gökhan

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 <[hidden email]> 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: [hidden email]
>> For additional commands, e-mail: [hidden email]
>>
>>

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

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.

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 <[hidden email]> 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: [hidden email]
>>> For additional commands, e-mail: [hidden email]
>>>
>>>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

Felix Schumacher

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 <[hidden email]>
>>> 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: [hidden email]
>>>> For additional commands, e-mail: [hidden email]
>>>>
>>>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email]
>> For additional commands, e-mail: [hidden email]
>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]