Re: Tomcat JDBC Pool Cleaner Deadlock Problem

2020-08-31 Thread 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 
>>> 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
>
>     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=truecharacterEncoding=latin5characterResultSet=latin5zeroDateTimeBehavior=convertToNullautoReconnect=trueinteractiveClient=true"
>    username="user"
>    password="pass"
>    initialSize="10"
>    maxActive="30"
>    maxIdle="15"
>    minIdle="10"
>    maxWait="3"
>    timeBetweenEvictionRunsMillis="5000"
>    minEvictableIdleTimeMillis="6"
>    removeAbandonedTimeout="600"
>    removeAbandoned="true"
>    logAbandoned="false"
>    testWhileIdle="true"
>    testOnBorrow="true"
>    testOnReturn="false"
>    validationQuery="/* ping */ SELECT 1"
>    validationInterval="3"
>    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
>     -
 

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

2020-08-31 Thread 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  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


  
url="jdbc:mysql://adress:3306/db?useUnicode=truecharacterEncoding=latin5characterResultSet=latin5zeroDateTimeBehavior=convertToNullautoReconnect=trueinteractiveClient=true"

   username="user"
   password="pass"
   initialSize="10"
   maxActive="30"
   maxIdle="15"
   minIdle="10"
   maxWait="3"
   timeBetweenEvictionRunsMillis="5000"
   minEvictableIdleTimeMillis="6"
   removeAbandonedTimeout="600"
   removeAbandoned="true"
   logAbandoned="false"
   testWhileIdle="true"
   testOnBorrow="true"
   testOnReturn="false"
   validationQuery="/* ping */ SELECT 1"
   validationInterval="3"
   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.(DatabaseMetaData.java:675)
  at

com.mysql.jdbc.JDBC4DatabaseMetaData.(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 

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

2020-08-31 Thread Felix Schumacher


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  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
>>>
>>> >>   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=truecharacterEncoding=latin5characterResultSet=latin5zeroDateTimeBehavior=convertToNullautoReconnect=trueinteractiveClient=true"
>>>   username="user"
>>>   password="pass"
>>>   initialSize="10"
>>>   maxActive="30"
>>>   maxIdle="15"
>>>   minIdle="10"
>>>   maxWait="3"
>>>   timeBetweenEvictionRunsMillis="5000"
>>>   minEvictableIdleTimeMillis="6"
>>>   removeAbandonedTimeout="600"
>>>   removeAbandoned="true"
>>>   logAbandoned="false"
>>>   testWhileIdle="true"
>>>   testOnBorrow="true"
>>>   testOnReturn="false"
>>>   validationQuery="/* ping */ SELECT 1"
>>>   validationInterval="3"
>>>   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.(DatabaseMetaData.java:675)
>>>  at
>> com.mysql.jdbc.JDBC4DatabaseMetaData.(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
>> 

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

2020-08-31 Thread 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 <
> felix.schumac...@internetallee.de> 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
>>>
>>> >>  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=truecharacterEncoding=latin5characterResultSet=latin5zeroDateTimeBehavior=convertToNullautoReconnect=trueinteractiveClient=true"
>>>  username="user"
>>>  password="pass"
>>>  initialSize="10"
>>>  maxActive="30"
>>>  maxIdle="15"
>>>  minIdle="10"
>>>  maxWait="3"
>>>  timeBetweenEvictionRunsMillis="5000"
>>>  minEvictableIdleTimeMillis="6"
>>>  removeAbandonedTimeout="600"
>>>  removeAbandoned="true"
>>>  logAbandoned="false"
>>>  testWhileIdle="true"
>>>  testOnBorrow="true"
>>>  testOnReturn="false"
>>>  validationQuery="/* ping */ SELECT 1"
>>>  validationInterval="3"
>>>  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.(DatabaseMetaData.java:675)
>>> at
>> com.mysql.jdbc.JDBC4DatabaseMetaData.(JDBC4DatabaseMetaData.java:39)
>>> at sun.reflect.GeneratedConstructorAccessor24.newInstance(Unknown
>> Source)
>>> at
>> 

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

2020-08-30 Thread 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.
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 <
felix.schumac...@internetallee.de> 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
> >
> >  >  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=truecharacterEncoding=latin5characterResultSet=latin5zeroDateTimeBehavior=convertToNullautoReconnect=trueinteractiveClient=true"
> >  username="user"
> >  password="pass"
> >  initialSize="10"
> >  maxActive="30"
> >  maxIdle="15"
> >  minIdle="10"
> >  maxWait="3"
> >  timeBetweenEvictionRunsMillis="5000"
> >  minEvictableIdleTimeMillis="6"
> >  removeAbandonedTimeout="600"
> >  removeAbandoned="true"
> >  logAbandoned="false"
> >  testWhileIdle="true"
> >  testOnBorrow="true"
> >  testOnReturn="false"
> >  validationQuery="/* ping */ SELECT 1"
> >  validationInterval="3"
> >  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.(DatabaseMetaData.java:675)
> > at
> com.mysql.jdbc.JDBC4DatabaseMetaData.(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)
> > 

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

2020-08-30 Thread 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.

On Sat, Aug 29, 2020 at 6:50 PM Phil Steitz  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
> >
> >  >   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=truecharacterEncoding=latin5characterResultSet=latin5zeroDateTimeBehavior=convertToNullautoReconnect=trueinteractiveClient=true"
> >   username="user"
> >   password="pass"
> >   initialSize="10"
> >   maxActive="30"
> >   maxIdle="15"
> >   minIdle="10"
> >   maxWait="3"
> >   timeBetweenEvictionRunsMillis="5000"
> >   minEvictableIdleTimeMillis="6"
> >   removeAbandonedTimeout="600"
> >   removeAbandoned="true"
> >   logAbandoned="false"
> >   testWhileIdle="true"
> >   testOnBorrow="true"
> >   testOnReturn="false"
> >   validationQuery="/* ping */ SELECT 1"
> >   validationInterval="3"
> >   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.(DatabaseMetaData.java:675)
> >  at
> com.mysql.jdbc.JDBC4DatabaseMetaData.(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
> 

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

2020-08-29 Thread Phil Steitz



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





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.(DatabaseMetaData.java:675)
 at 
com.mysql.jdbc.JDBC4DatabaseMetaData.(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 

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

2020-08-27 Thread Felix Schumacher


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
>
>   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=truecharacterEncoding=latin5characterResultSet=latin5zeroDateTimeBehavior=convertToNullautoReconnect=trueinteractiveClient=true"
>  username="user"
>  password="pass"
>  initialSize="10"
>  maxActive="30"
>  maxIdle="15"
>  minIdle="10"
>  maxWait="3"
>  timeBetweenEvictionRunsMillis="5000"
>  minEvictableIdleTimeMillis="6"
>  removeAbandonedTimeout="600"
>  removeAbandoned="true"
>  logAbandoned="false"
>  testWhileIdle="true"
>  testOnBorrow="true"
>  testOnReturn="false"
>  validationQuery="/* ping */ SELECT 1"
>  validationInterval="3"
>  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.(DatabaseMetaData.java:675)
> at 
> com.mysql.jdbc.JDBC4DatabaseMetaData.(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 
> 

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

2020-08-27 Thread 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'=> '3',
'timeBetweenEvictionRunsMillis' => '3',
'minEvictableIdleTimeMillis'=> '3',
'removeAbandonedTimeout'=> '60',
'numTestsPerEvictionRun'=> '3',

On Thu, Aug 27, 2020 at 1:44 PM Christopher Schultz
 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
> >
> >  > type="javax.sql.DataSource"
> > factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"
> > driverClassName="com.mysql.jdbc.Driver"
> > url="jdbc:mysql://adress:3306/db?useUnicode=truecharacterEncoding
> =latin5characterResultSet=latin5zeroDateTimeBehavior=convertTo
> NullautoReconnect=trueinteractiveClient=true"
> >
> >
> username="user"
> > password="pass" initialSize="10" maxActive="30" maxIdle="15"
> > minIdle="10" maxWait="3" timeBetweenEvictionRunsMillis="5000"
> > minEvictableIdleTimeMillis="6" removeAbandonedTimeout="600"
> > removeAbandoned="true" logAbandoned="false" testWhileIdle="true"
> > testOnBorrow="true" testOnReturn="false" validationQuery="/* ping
> > */ SELECT 1" validationInterval="3" 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.(DatabaseMetaData.java:675)
> > at
> > com.mysql.jdbc.JDBC4DatabaseMetaData.(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
> > 

Re: Tomcat JDBC Pool Cleaner Deadlock Problem

2020-08-27 Thread Christopher Schultz
-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
>
>  type="javax.sql.DataSource"
> factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"
> driverClassName="com.mysql.jdbc.Driver"
> url="jdbc:mysql://adress:3306/db?useUnicode=truecharacterEncoding
=latin5characterResultSet=latin5zeroDateTimeBehavior=convertTo
NullautoReconnect=trueinteractiveClient=true"
>
>
username="user"
> password="pass" initialSize="10" maxActive="30" maxIdle="15"
> minIdle="10" maxWait="3" timeBetweenEvictionRunsMillis="5000"
> minEvictableIdleTimeMillis="6" removeAbandonedTimeout="600"
> removeAbandoned="true" logAbandoned="false" testWhileIdle="true"
> testOnBorrow="true" testOnReturn="false" validationQuery="/* ping
> */ SELECT 1" validationInterval="3" 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.(DatabaseMetaData.java:675)
> at
> com.mysql.jdbc.JDBC4DatabaseMetaData.(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
>