You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by marko lugarič <ma...@gmail.com> on 2013/11/18 09:48:46 UTC

Tomcat connection pool "bleeding" under heavy load

Hello!

We have received an issue from our customer that after some time in
production
they get empty connection pool. After some time we managed to reproduce
their
problem in our test environment with smaller number of pool connections.

So generally we have a problem that if connection pool is under heavy load
(meaning most of the time all the connections are taken - active) it starts
to
loose database connections (we call it bleed): they are lost from the
perspective of Tomcat but they are very much alive when we check then on
the
database side.

We are using Apache Tomcat 7.0.47 running on java 1.6. Database is SQL
Server
2008R2 and we are using Hibernate as persistence provider. Our
configuration
is defined in server.xml in the GlobalNamingResources section (referenced
from
context.xml):

<Resource
    name="jdbc/ChiDS"
    auth="Container"
    type="javax.sql.DataSource"
    factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"
    driverClassName="com.microsoft.sqlserver.jdbc.SQLServerDriver"
    url="jdbc:sqlserver://*****;databaseName=chiTestDB"
    username="*****"
    password="*****"
    initialSize="2"
    maxActive="5"
    maxIdle="4"
    minIdle="2"
    maxWait="15000"
    timeBetweenEvictionRunsMillis="30000"
    testOnBorrow="true"
    testOnReturn="false"
    testOnIdle="false"
    validationQuery="SELECT 1"
    validationInterval="30000"
    removeAbandoned="true"
    removeAbandonedTimeout="60"
    useEquals="false"/>

I will explain in detail what happens. For better understanding I am also
providing graph of idle and active connections from Java VisualVM MBeans
viewer: http://img11.imageshack.us/img11/6888/fm4j.jpg

So we start the server and connect clients to the server that generate
small
database load. After that we order half of our clients to start generating
operations that result in medium database load (I think around 300
transactions
per second). We can see from the graph that connection pool is behaving
normally (sometimes all 5 connections are taken, sometimes not - if we
would
run test like this all day everything would be OK). So after 7 minutes we
increase the load by 100% (other half of clients start to do operations).
The load is bigger than 5 pool connections can handle: pretty much all the
time all 5 connections are active so we can soon expect that server
application
logic will start to receive exceptions that jdbc connection is not
available
(this should happen if application logic does not receive pool connection
in 15
seconds). Indeed this happens and the following exception is thrown:

aused by: org.hibernate.exception.GenericJDBCException: Cannot open
connection
    at
org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
    at
org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
    at
org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
    at
org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
    at
org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449)
    at
org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
    at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
    at
org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
    at
org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1463)
    at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:60)
... 18 more
Caused by: java.sql.SQLException: Pool wait interrupted.
    at
org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:655)
    at
org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:188)
    at
org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
    at
org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:92)
    at
org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
... 23 more
Caused by: java.lang.InterruptedException
    at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1024)
    at
java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1303)
    at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:253)
    at
org.apache.tomcat.jdbc.pool.FairBlockingQueue.poll(FairBlockingQueue.java:151)
    at
org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:650)

But here something goes wrong because active connections count drops by 1
and
never goes back even though database load is still the same. Judging from
the
graph at this moment pool is giving only 4 pool connections to the
application.
Pretty soon the same exception is thrown again reducing the active pool
count
by 1. And then very quickly same exception is thrown 3 more times and pool
has
no active or idle connections. After this another type of exceptions starts
to
pop in log file:

Caused by: javax.persistence.PersistenceException:
org.hibernate.exception.GenericJDBCException: Cannot open connection
    at
org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1235)
    at
org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1168)
    at
org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:1245)
    at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:63)
    at
com.hsl.chi.persistence.dao.jpa.DAO.beginEntityTransaction(DAO.java:1505)
    at
com.hsl.chi.persistence.dao.jpa.DAO.beginFirstSubOperation(DAO.java:992)
    at
com.hsl.chi.persistence.dao.jpa.SequenceDAO.internalResetSequence(SequenceDAO.java:568)
... 9 more
Caused by: org.hibernate.exception.GenericJDBCException: Cannot open
connection
    at
org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
    at
org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
    at
org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
    at
org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
    at
org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449)
    at
org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
    at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
    at
org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
    at
org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1463)
    at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:60)
... 12 more
Caused by: org.apache.tomcat.jdbc.pool.PoolExhaustedException:
[[ProtocolHandler]-[pool-1-thread-113]] Timeout: Pool empty. Unable to
fetch a connection in 15 seconds, none available[size:5; busy:0; idle:0;
lastwait:15000].
    at
org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:674)
    at
org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:188)
    at
org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
    at
org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:92)
    at
org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)

So from the Tomcat point of view we have no jdbc connections to the
database
in the pool. From this point no database operation can succeed: even if
load
is reduced to minimum - every database operation fails from application.
Then we check the database side: SQL server creates its internal process
for
each jdbc connection: we can see all 5 connections much alive doing
nothing.
Since we are using hibernate we were quickly able to do the same test on
PostgreSQL database and identical scenario happens: PostgreSQL shows
5 idle processes while pool is empty. The only thing we can do here is to
restart the Tomcat.

We also tried other configurations (Tomcat 7.0.32, hibernate library was
updated to latest version, we used PostgreSQL server instead of SQL server)
and different connection pool properties but without any success - we
always
end up with empty pool. Tomcat properties that we tried:

logAbandoned="true" - did not log anything (I guess stack trace should be
thrown to console, log file if connection would not be  closed from
application?), so I guess hibernate is closing connections properly
(we are always calling entity manager close method when we finish).

jdbcInterceptors="StatementFinalizer;SlowQueryReportJmx(threshold=10000)" -
statement finalizier did not help

testOnReturn="true", testOnIdle="true", propagateInterruptState="true" -
did not help


So the last option was to change connection pool: we used C3P0 connection
pool
with properties that are similar in meaning as Tomcat ones. We repeated the
above test case and it is working correctly. We have left it with full load
half an hour in which we get a lot of exceptions that application did not
receive connection but pool is still working OK (all connections are active
almost all the time). Exception that is being thrown:
com.mchange.v2.resourcepool.BasicResourcePool@437ff0 -- an attempt to
checkout
a resource was interrupted, and the pool is still live: some other thread
must
have either interrupted the Thread attempting checkout!
java.lang.InterruptedException . Then we reduce the load and exceptions are
soon gone since 5 connection can handle them. Here is the configuration from
server.xml for C3P0:

<Resource
    name="jdbc/ChiDS"
    auth="Container"
    type="com.mchange.v2.c3p0.ComboPooledDataSource"
    dataSourceName="jdbc/ChiDS"
    factory="org.apache.naming.factory.BeanFactory"
    driverClass="com.microsoft.sqlserver.jdbc.SQLServerDriver"
    jdbcUrl="jdbc:sqlserver://*****;databaseName=chiDB"
    user="*****"
    password="*****"
    initialPoolSize="2"
    minPoolSize="2"
    maxPoolSize="5"
    preferredTestQuery="SELECT 1"
    testConnectionOnCheckin="true"
    idleConnectionTestPeriod="30"
    numHelperThreads="5"/>

Currently our customer raised maxActive to bigger number but i guess this
will
not do once they will start increasing the number of clients (our
application
has big amount of transactions) and they will have to change connection
pool.
Are there any additional configuration setting I can try on Tomcat
connection
pool, otherwise this looks like a bug?

regards, Marko

Re: Tomcat connection pool "bleeding" under heavy load

Posted by David Bullock <da...@machaira.com.au>.
On 19 November 2013 14:59, Caldarale, Charles R
<Ch...@unisys.com> wrote:
>> From: David Bullock [mailto:david.bullock@machaira.com.au]
>> Subject: Re: Tomcat connection pool "bleeding" under heavy load
>
>> In PooledConnection#borrow(int,String,String) when handling
>> InterruptedException, the code there does:
>
>>    Thread.interrupted();//clear the flag, and bail out
>
>> but if the comment is correct, then the code is wrong (should
>> be Thread.isInterrupted()).
>
> No, Thread.interrupted() is a static method that checks if the _current_ thread has been interrupted.  Calling Thread.isInterrupted() would be illegal, since that is an instance method, and is used primarily to determine if some other thread has been interrupted.  Also, the isInterrupted() method does not clear the interrupted flag for the target thread, whereas Thread.interrupted() does clear it for the current thread.

True.  Sorry about that mis-information.

cheers,
David.

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: Tomcat connection pool "bleeding" under heavy load

Posted by "Caldarale, Charles R" <Ch...@unisys.com>.
> From: David Bullock [mailto:david.bullock@machaira.com.au] 
> Subject: Re: Tomcat connection pool "bleeding" under heavy load

> In PooledConnection#borrow(int,String,String) when handling
> InterruptedException, the code there does:

>    Thread.interrupted();//clear the flag, and bail out

> but if the comment is correct, then the code is wrong (should
> be Thread.isInterrupted()).

No, Thread.interrupted() is a static method that checks if the _current_ thread has been interrupted.  Calling Thread.isInterrupted() would be illegal, since that is an instance method, and is used primarily to determine if some other thread has been interrupted.  Also, the isInterrupted() method does not clear the interrupted flag for the target thread, whereas Thread.interrupted() does clear it for the current thread.

 - Chuck


THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers.


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat connection pool "bleeding" under heavy load

Posted by David Bullock <da...@machaira.com.au>.
In PooledConnection#borrow(int,String,String) when handling
InterruptedException, the code there does:

   Thread.interrupted();//clear the flag, and bail out

but if the comment is correct, then the code is wrong (should
be Thread.isInterrupted()).  However, the entire line is probably
not necessary - using the java.util.concurrent contracts, a threads'
interruption status is usually cleared when InterruptedException
is thrown.

The 'leakiness' of the pool is actually in

  org.apache.tomcat.jdbc.pool.FairBlockingQueue#poll()

If the line (!c.await(timeout, unit)) exits via an
InterruptedException, the the 'exchangecountdownlatch' is never
removed from the waitlist ... connections will be 'exchanged' with
threads which will never rendezvous.

But why is InterruptedException being thrown anyway?  That'll be
because the Tomcat worker thread trying to acquire a connection
gets issued aWorkerThread.interrupt() for taking too long.  So
adjusting some timeout settings (to make Tomcat more patient
than the connection pool) should give a workaround.  DBCP had
a better grasp of what was going on when reporting this.

cheers,
David
David Bullock
Machaira Enterprises Pty Ltd

PO Box 31
Canowindra NSW 2804

02 6344 1100
http://machaira.com.au/


On 18 November 2013 19:48, marko lugarič <ma...@gmail.com> wrote:
> Hello!
>
> We have received an issue from our customer that after some time in
> production
> they get empty connection pool. After some time we managed to reproduce
> their
> problem in our test environment with smaller number of pool connections.
>
> So generally we have a problem that if connection pool is under heavy load
> (meaning most of the time all the connections are taken - active) it starts
> to
> loose database connections (we call it bleed): they are lost from the
> perspective of Tomcat but they are very much alive when we check then on
> the
> database side.
>
> We are using Apache Tomcat 7.0.47 running on java 1.6. Database is SQL
> Server
> 2008R2 and we are using Hibernate as persistence provider. Our
> configuration
> is defined in server.xml in the GlobalNamingResources section (referenced
> from
> context.xml):
>
> <Resource
>     name="jdbc/ChiDS"
>     auth="Container"
>     type="javax.sql.DataSource"
>     factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"
>     driverClassName="com.microsoft.sqlserver.jdbc.SQLServerDriver"
>     url="jdbc:sqlserver://*****;databaseName=chiTestDB"
>     username="*****"
>     password="*****"
>     initialSize="2"
>     maxActive="5"
>     maxIdle="4"
>     minIdle="2"
>     maxWait="15000"
>     timeBetweenEvictionRunsMillis="30000"
>     testOnBorrow="true"
>     testOnReturn="false"
>     testOnIdle="false"
>     validationQuery="SELECT 1"
>     validationInterval="30000"
>     removeAbandoned="true"
>     removeAbandonedTimeout="60"
>     useEquals="false"/>
>
> I will explain in detail what happens. For better understanding I am also
> providing graph of idle and active connections from Java VisualVM MBeans
> viewer: http://img11.imageshack.us/img11/6888/fm4j.jpg
>
> So we start the server and connect clients to the server that generate
> small
> database load. After that we order half of our clients to start generating
> operations that result in medium database load (I think around 300
> transactions
> per second). We can see from the graph that connection pool is behaving
> normally (sometimes all 5 connections are taken, sometimes not - if we
> would
> run test like this all day everything would be OK). So after 7 minutes we
> increase the load by 100% (other half of clients start to do operations).
> The load is bigger than 5 pool connections can handle: pretty much all the
> time all 5 connections are active so we can soon expect that server
> application
> logic will start to receive exceptions that jdbc connection is not
> available
> (this should happen if application logic does not receive pool connection
> in 15
> seconds). Indeed this happens and the following exception is thrown:
>
> aused by: org.hibernate.exception.GenericJDBCException: Cannot open
> connection
>     at
> org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
>     at
> org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
>     at
> org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
>     at
> org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
>     at
> org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449)
>     at
> org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
>     at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
>     at
> org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
>     at
> org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1463)
>     at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:60)
> ... 18 more
> Caused by: java.sql.SQLException: Pool wait interrupted.
>     at
> org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:655)
>     at
> org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:188)
>     at
> org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
>     at
> org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:92)
>     at
> org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
> ... 23 more
> Caused by: java.lang.InterruptedException
>     at
> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1024)
>     at
> java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1303)
>     at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:253)
>     at
> org.apache.tomcat.jdbc.pool.FairBlockingQueue.poll(FairBlockingQueue.java:151)
>     at
> org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:650)
>
> But here something goes wrong because active connections count drops by 1
> and
> never goes back even though database load is still the same. Judging from
> the
> graph at this moment pool is giving only 4 pool connections to the
> application.
> Pretty soon the same exception is thrown again reducing the active pool
> count
> by 1. And then very quickly same exception is thrown 3 more times and pool
> has
> no active or idle connections. After this another type of exceptions starts
> to
> pop in log file:
>
> Caused by: javax.persistence.PersistenceException:
> org.hibernate.exception.GenericJDBCException: Cannot open connection
>     at
> org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1235)
>     at
> org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1168)
>     at
> org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:1245)
>     at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:63)
>     at
> com.hsl.chi.persistence.dao.jpa.DAO.beginEntityTransaction(DAO.java:1505)
>     at
> com.hsl.chi.persistence.dao.jpa.DAO.beginFirstSubOperation(DAO.java:992)
>     at
> com.hsl.chi.persistence.dao.jpa.SequenceDAO.internalResetSequence(SequenceDAO.java:568)
> ... 9 more
> Caused by: org.hibernate.exception.GenericJDBCException: Cannot open
> connection
>     at
> org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
>     at
> org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
>     at
> org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
>     at
> org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
>     at
> org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449)
>     at
> org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
>     at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
>     at
> org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
>     at
> org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1463)
>     at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:60)
> ... 12 more
> Caused by: org.apache.tomcat.jdbc.pool.PoolExhaustedException:
> [[ProtocolHandler]-[pool-1-thread-113]] Timeout: Pool empty. Unable to
> fetch a connection in 15 seconds, none available[size:5; busy:0; idle:0;
> lastwait:15000].
>     at
> org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:674)
>     at
> org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:188)
>     at
> org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
>     at
> org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:92)
>     at
> org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
>
> So from the Tomcat point of view we have no jdbc connections to the
> database
> in the pool. From this point no database operation can succeed: even if
> load
> is reduced to minimum - every database operation fails from application.
> Then we check the database side: SQL server creates its internal process
> for
> each jdbc connection: we can see all 5 connections much alive doing
> nothing.
> Since we are using hibernate we were quickly able to do the same test on
> PostgreSQL database and identical scenario happens: PostgreSQL shows
> 5 idle processes while pool is empty. The only thing we can do here is to
> restart the Tomcat.
>
> We also tried other configurations (Tomcat 7.0.32, hibernate library was
> updated to latest version, we used PostgreSQL server instead of SQL server)
> and different connection pool properties but without any success - we
> always
> end up with empty pool. Tomcat properties that we tried:
>
> logAbandoned="true" - did not log anything (I guess stack trace should be
> thrown to console, log file if connection would not be  closed from
> application?), so I guess hibernate is closing connections properly
> (we are always calling entity manager close method when we finish).
>
> jdbcInterceptors="StatementFinalizer;SlowQueryReportJmx(threshold=10000)" -
> statement finalizier did not help
>
> testOnReturn="true", testOnIdle="true", propagateInterruptState="true" -
> did not help
>
>
> So the last option was to change connection pool: we used C3P0 connection
> pool
> with properties that are similar in meaning as Tomcat ones. We repeated the
> above test case and it is working correctly. We have left it with full load
> half an hour in which we get a lot of exceptions that application did not
> receive connection but pool is still working OK (all connections are active
> almost all the time). Exception that is being thrown:
> com.mchange.v2.resourcepool.BasicResourcePool@437ff0 -- an attempt to
> checkout
> a resource was interrupted, and the pool is still live: some other thread
> must
> have either interrupted the Thread attempting checkout!
> java.lang.InterruptedException . Then we reduce the load and exceptions are
> soon gone since 5 connection can handle them. Here is the configuration from
> server.xml for C3P0:
>
> <Resource
>     name="jdbc/ChiDS"
>     auth="Container"
>     type="com.mchange.v2.c3p0.ComboPooledDataSource"
>     dataSourceName="jdbc/ChiDS"
>     factory="org.apache.naming.factory.BeanFactory"
>     driverClass="com.microsoft.sqlserver.jdbc.SQLServerDriver"
>     jdbcUrl="jdbc:sqlserver://*****;databaseName=chiDB"
>     user="*****"
>     password="*****"
>     initialPoolSize="2"
>     minPoolSize="2"
>     maxPoolSize="5"
>     preferredTestQuery="SELECT 1"
>     testConnectionOnCheckin="true"
>     idleConnectionTestPeriod="30"
>     numHelperThreads="5"/>
>
> Currently our customer raised maxActive to bigger number but i guess this
> will
> not do once they will start increasing the number of clients (our
> application
> has big amount of transactions) and they will have to change connection
> pool.
> Are there any additional configuration setting I can try on Tomcat
> connection
> pool, otherwise this looks like a bug?
>
> regards, Marko

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat connection pool "bleeding" under heavy load

Posted by David Bullock <da...@machaira.com.au>.
Marko wrote:

> In that case debugging looks like the only option?

Nobody yet disputed:

> The 'leakiness' of the pool is actually in
>   org.apache.tomcat.jdbc.pool.FairBlockingQueue#poll()
> If the line (!c.await(timeout, unit)) exits via an
> InterruptedException, the the 'exchangecountdownlatch' is never
> removed from the waitlist ... connections will be 'exchanged' with
> threads which will never rendezvous.

To labour the point:

On line 650 of
http://svn.apache.org/viewvc/tomcat/trunk/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/ConnectionPool.java?view=markup
there is a call to 'idle.poll()'.   'idle' is a FairBlockingQueue
(assigned in 448).

On lines 150 to 155 of FairBlockingQueue
http://svn.apache.org/viewvc/tomcat/trunk/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/FairBlockingQueue.java?revision=1432842&view=markup,
the poll(long,TimeUnit) method **does not invoke
waiters.remove(c) if line 150 throws InterruptedException**.

That's a bug that explains the 'bleed'.  Eventutally, a connection is offered to
the queue,   The pool selects a 'waiter' to give the connection to,
but the thread
supposedly awaiting on the latch is dead.  The connection escapes from pool,
and is never put back.


I offered a workaround:

> But why is InterruptedException being thrown anyway?  That'll be
> because the Tomcat worker thread trying to acquire a connection
> gets issued aWorkerThread.interrupt() for taking too long.  So
> adjusting some timeout settings (to make Tomcat more patient
> than the connection pool) should give a workaround.  DBCP had
> a better grasp of what was going on when reporting this.

Or I guess, there could be some other fault that's calling interrupt() on
the thread, but a timeout from the container (which owns the thread) is
the most likely option.

cheers,
David.

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat connection pool "bleeding" under heavy load

Posted by marko lugarič <ma...@gmail.com>.
Hello

I guess you are suggesting to compile this class with the changes you
propose
and test it?

regards, marko


On Thu, Nov 21, 2013 at 1:58 AM, David Bullock <
david.bullock@machaira.com.au> wrote:

> Oh, and 'throw e;' at the end of the handler :-)
> David Bullock
> Machaira Enterprises Pty Ltd
>
> PO Box 31
> Canowindra NSW 2804
>
> 02 6344 1100
> http://machaira.com.au/
>
>
> On 21 November 2013 11:48, David Bullock <da...@machaira.com.au>
> wrote:
> > Line 150 of org.apache.tomcat.jdbc.pool.FairBlockingQueue can throw
> > InterruptedException, which should be handled by:
> >
> > catch (InterruptedException e) {
> >    lock.lock();
> >    waiters.remove(c); // prevent future threads from offering to this
> > thread, since we are about to die
> >    lock.unlock();
> >    if (c.getCount() == 0) { // was given a connection between
> >                                     // when the exception was thrown we
> acquired
> >                                     // the lock.  This seems unlikely,
> so we are
> >                                     // happy to have let go of the
> > lock and re-acquire
> >                                     // if necessary
> >        lock.lock();
> >        items.addFirst(c.getItem()); // return to the head of the
> > queue, as per policy in offer()
> >        lock.unlock();
> >    }
> > }
> >
> > You're welcome.
> >
> > cf
> http://svn.apache.org/viewvc/tomcat/trunk/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/FairBlockingQueue.java?revision=1432842&view=markup
> >
> > public E poll(long timeout, TimeUnit unit) throws InterruptedException {
> > 135        E result = null;
> > 136        final ReentrantLock lock = this.lock;
> > 137        try {
> > 138            //acquire the global lock until we know what to do
> > 139            lock.lock();
> > 140            //check to see if we have objects
> > 141            result = items.poll();
> > 142            if (result==null && timeout>0) {
> > 143                //the queue is empty we will wait for an object
> > 144                ExchangeCountDownLatch<E> c = new
> > ExchangeCountDownLatch<>(1);
> > 145                //add to the bottom of the wait list
> > 146                waiters.addLast(c);
> > 147                //unlock the global lock
> > 148                lock.unlock();
> > 149                //wait for the specified timeout
> > 150                if (!c.await(timeout, unit)) {
> > 151                    //if we timed out, remove ourselves from the
> waitlist
> > 152                    lock.lock();
> > 153                    waiters.remove(c);
> > 154                    lock.unlock();
> > 155                }
> > 156                //return the item we received, can be null if we
> timed out
> > 157                result = c.getItem();
> > 158            } else {
> > 159                //we have an object, release
> > 160                lock.unlock();
> > 161            }
> > 162        } finally {
> > 163            if (lock.isHeldByCurrentThread()) {
> > 164                lock.unlock();
> > 165            }
> > 166        }
> > 167        return result;
> > 168    }
> > David Bullock
> > Machaira Enterprises Pty Ltd
> >
> > PO Box 31
> > Canowindra NSW 2804
> >
> > 02 6344 1100
> > http://machaira.com.au/
> >
> >
> > On 21 November 2013 04:58, Christopher Schultz
> > <ch...@christopherschultz.net> wrote:
> >> -----BEGIN PGP SIGNED MESSAGE-----
> >> Hash: SHA256
> >>
> >> Marko,
> >>
> >> On 11/20/13, 12:07 PM, marko lugarič wrote:
> >>> I have repeated the test with logAbandoned set to "true" and left
> >>> it half hour after pool is empty. There are a lot of exceptions
> >>> (Pool empty. Unable to fetch a connection in 15 seconds and Pool
> >>> wait interrupted) but i don't know what exactly to search (search
> >>> with Abandoned did not produce anything). I have already tried
> >>> using StatementFinalizer interceptor but it did not do anything to
> >>> prevent pool from being empty.
> >>
> >> Can you work-up a simple testcase webapp and load test to reproduce
> >> this problem? If so, please file a bug against tomcat-pool in Bugzilla
> >> and attach the simple webapp and test harness.
> >>
> >> - -chris
> >> -----BEGIN PGP SIGNATURE-----
> >> Version: GnuPG v1.4.15 (Darwin)
> >> Comment: GPGTools - http://gpgtools.org
> >> Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
> >>
> >> iQIcBAEBCAAGBQJSjPhBAAoJEBzwKT+lPKRYQxIQAMHi+9z9jCbzulHiXns/Mt3p
> >> J6w6K6nFCbDOgj7noYfwGf2eBINPQ77ywhF56pzBgn6v2wXWG21NRXTLfHxJJM/s
> >> i1Ol9qp9mEUz3gmcumHbXU+RBBn1CbSh6D8cdVZDsX6tGF4BuzNtseZ0PRq7ZI5A
> >> fi6dyPA5sZf1skfHIOBhmWT7VB7UGud03YmxnKhe3e7N2ZtDN2AJYNhU0haSHd1m
> >> 1DGlCYxmMlK5mbqRA3RGWFTrnDmEvhBnSTLJaLywAojN8XHnNAH4fx4+MCT5GXrV
> >> h1EL1PhvFnpbQ5haTOHNIwCNtW3OPwdLsXXVimOVF6UvEZepF3pDJUL0KVV+Kfem
> >> p+r5BjkcjZ7LYirDBPFCsIovSwFcLrLScPUKbDHhF0Re5E7K7EtXuVuGGCJqWRsf
> >> 8w8Z2pcyBIhX85+D+kBZ2m6MFODXnEqTQeGbFhzffuPXV/DuvipARpFg9s8uo1ws
> >> 85NEtFzHjNblgxVxFaEgbbWulKT1ZNZerAMRnGDh9W2ngMjwYuQfevbJghUkM5b4
> >> nMc/aNU2mg10lneRwTUIJ0f/aGfiCQegjSSEYGIDi1LcDHDkI4GPmMz3gGIfItBs
> >> yBEWXKn8aqVqVEVKjFzq5tD0kw9zyCEErYJH6N7o0HYmHHYfPxgz5Cr8gnnayUac
> >> Ru2Z7Ur1lnZZnC72oUwz
> >> =bJFf
> >> -----END PGP SIGNATURE-----
> >>
> >> ---------------------------------------------------------------------
> >> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> >> For additional commands, e-mail: users-help@tomcat.apache.org
> >>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
>

Re: Tomcat connection pool "bleeding" under heavy load

Posted by David Bullock <da...@machaira.com.au>.
Oh, and 'throw e;' at the end of the handler :-)
David Bullock
Machaira Enterprises Pty Ltd

PO Box 31
Canowindra NSW 2804

02 6344 1100
http://machaira.com.au/


On 21 November 2013 11:48, David Bullock <da...@machaira.com.au> wrote:
> Line 150 of org.apache.tomcat.jdbc.pool.FairBlockingQueue can throw
> InterruptedException, which should be handled by:
>
> catch (InterruptedException e) {
>    lock.lock();
>    waiters.remove(c); // prevent future threads from offering to this
> thread, since we are about to die
>    lock.unlock();
>    if (c.getCount() == 0) { // was given a connection between
>                                     // when the exception was thrown we acquired
>                                     // the lock.  This seems unlikely, so we are
>                                     // happy to have let go of the
> lock and re-acquire
>                                     // if necessary
>        lock.lock();
>        items.addFirst(c.getItem()); // return to the head of the
> queue, as per policy in offer()
>        lock.unlock();
>    }
> }
>
> You're welcome.
>
> cf http://svn.apache.org/viewvc/tomcat/trunk/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/FairBlockingQueue.java?revision=1432842&view=markup
>
> public E poll(long timeout, TimeUnit unit) throws InterruptedException {
> 135        E result = null;
> 136        final ReentrantLock lock = this.lock;
> 137        try {
> 138            //acquire the global lock until we know what to do
> 139            lock.lock();
> 140            //check to see if we have objects
> 141            result = items.poll();
> 142            if (result==null && timeout>0) {
> 143                //the queue is empty we will wait for an object
> 144                ExchangeCountDownLatch<E> c = new
> ExchangeCountDownLatch<>(1);
> 145                //add to the bottom of the wait list
> 146                waiters.addLast(c);
> 147                //unlock the global lock
> 148                lock.unlock();
> 149                //wait for the specified timeout
> 150                if (!c.await(timeout, unit)) {
> 151                    //if we timed out, remove ourselves from the waitlist
> 152                    lock.lock();
> 153                    waiters.remove(c);
> 154                    lock.unlock();
> 155                }
> 156                //return the item we received, can be null if we timed out
> 157                result = c.getItem();
> 158            } else {
> 159                //we have an object, release
> 160                lock.unlock();
> 161            }
> 162        } finally {
> 163            if (lock.isHeldByCurrentThread()) {
> 164                lock.unlock();
> 165            }
> 166        }
> 167        return result;
> 168    }
> David Bullock
> Machaira Enterprises Pty Ltd
>
> PO Box 31
> Canowindra NSW 2804
>
> 02 6344 1100
> http://machaira.com.au/
>
>
> On 21 November 2013 04:58, Christopher Schultz
> <ch...@christopherschultz.net> wrote:
>> -----BEGIN PGP SIGNED MESSAGE-----
>> Hash: SHA256
>>
>> Marko,
>>
>> On 11/20/13, 12:07 PM, marko lugarič wrote:
>>> I have repeated the test with logAbandoned set to "true" and left
>>> it half hour after pool is empty. There are a lot of exceptions
>>> (Pool empty. Unable to fetch a connection in 15 seconds and Pool
>>> wait interrupted) but i don't know what exactly to search (search
>>> with Abandoned did not produce anything). I have already tried
>>> using StatementFinalizer interceptor but it did not do anything to
>>> prevent pool from being empty.
>>
>> Can you work-up a simple testcase webapp and load test to reproduce
>> this problem? If so, please file a bug against tomcat-pool in Bugzilla
>> and attach the simple webapp and test harness.
>>
>> - -chris
>> -----BEGIN PGP SIGNATURE-----
>> Version: GnuPG v1.4.15 (Darwin)
>> Comment: GPGTools - http://gpgtools.org
>> Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
>>
>> iQIcBAEBCAAGBQJSjPhBAAoJEBzwKT+lPKRYQxIQAMHi+9z9jCbzulHiXns/Mt3p
>> J6w6K6nFCbDOgj7noYfwGf2eBINPQ77ywhF56pzBgn6v2wXWG21NRXTLfHxJJM/s
>> i1Ol9qp9mEUz3gmcumHbXU+RBBn1CbSh6D8cdVZDsX6tGF4BuzNtseZ0PRq7ZI5A
>> fi6dyPA5sZf1skfHIOBhmWT7VB7UGud03YmxnKhe3e7N2ZtDN2AJYNhU0haSHd1m
>> 1DGlCYxmMlK5mbqRA3RGWFTrnDmEvhBnSTLJaLywAojN8XHnNAH4fx4+MCT5GXrV
>> h1EL1PhvFnpbQ5haTOHNIwCNtW3OPwdLsXXVimOVF6UvEZepF3pDJUL0KVV+Kfem
>> p+r5BjkcjZ7LYirDBPFCsIovSwFcLrLScPUKbDHhF0Re5E7K7EtXuVuGGCJqWRsf
>> 8w8Z2pcyBIhX85+D+kBZ2m6MFODXnEqTQeGbFhzffuPXV/DuvipARpFg9s8uo1ws
>> 85NEtFzHjNblgxVxFaEgbbWulKT1ZNZerAMRnGDh9W2ngMjwYuQfevbJghUkM5b4
>> nMc/aNU2mg10lneRwTUIJ0f/aGfiCQegjSSEYGIDi1LcDHDkI4GPmMz3gGIfItBs
>> yBEWXKn8aqVqVEVKjFzq5tD0kw9zyCEErYJH6N7o0HYmHHYfPxgz5Cr8gnnayUac
>> Ru2Z7Ur1lnZZnC72oUwz
>> =bJFf
>> -----END PGP SIGNATURE-----
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
>>

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat connection pool "bleeding" under heavy load

Posted by David Bullock <da...@machaira.com.au>.
Line 150 of org.apache.tomcat.jdbc.pool.FairBlockingQueue can throw
InterruptedException, which should be handled by:

catch (InterruptedException e) {
   lock.lock();
   waiters.remove(c); // prevent future threads from offering to this
thread, since we are about to die
   lock.unlock();
   if (c.getCount() == 0) { // was given a connection between
                                    // when the exception was thrown we acquired
                                    // the lock.  This seems unlikely, so we are
                                    // happy to have let go of the
lock and re-acquire
                                    // if necessary
       lock.lock();
       items.addFirst(c.getItem()); // return to the head of the
queue, as per policy in offer()
       lock.unlock();
   }
}

You're welcome.

cf http://svn.apache.org/viewvc/tomcat/trunk/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/FairBlockingQueue.java?revision=1432842&view=markup

public E poll(long timeout, TimeUnit unit) throws InterruptedException {
135        E result = null;
136        final ReentrantLock lock = this.lock;
137        try {
138            //acquire the global lock until we know what to do
139            lock.lock();
140            //check to see if we have objects
141            result = items.poll();
142            if (result==null && timeout>0) {
143                //the queue is empty we will wait for an object
144                ExchangeCountDownLatch<E> c = new
ExchangeCountDownLatch<>(1);
145                //add to the bottom of the wait list
146                waiters.addLast(c);
147                //unlock the global lock
148                lock.unlock();
149                //wait for the specified timeout
150                if (!c.await(timeout, unit)) {
151                    //if we timed out, remove ourselves from the waitlist
152                    lock.lock();
153                    waiters.remove(c);
154                    lock.unlock();
155                }
156                //return the item we received, can be null if we timed out
157                result = c.getItem();
158            } else {
159                //we have an object, release
160                lock.unlock();
161            }
162        } finally {
163            if (lock.isHeldByCurrentThread()) {
164                lock.unlock();
165            }
166        }
167        return result;
168    }
David Bullock
Machaira Enterprises Pty Ltd

PO Box 31
Canowindra NSW 2804

02 6344 1100
http://machaira.com.au/


On 21 November 2013 04:58, Christopher Schultz
<ch...@christopherschultz.net> wrote:
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
>
> Marko,
>
> On 11/20/13, 12:07 PM, marko lugarič wrote:
>> I have repeated the test with logAbandoned set to "true" and left
>> it half hour after pool is empty. There are a lot of exceptions
>> (Pool empty. Unable to fetch a connection in 15 seconds and Pool
>> wait interrupted) but i don't know what exactly to search (search
>> with Abandoned did not produce anything). I have already tried
>> using StatementFinalizer interceptor but it did not do anything to
>> prevent pool from being empty.
>
> Can you work-up a simple testcase webapp and load test to reproduce
> this problem? If so, please file a bug against tomcat-pool in Bugzilla
> and attach the simple webapp and test harness.
>
> - -chris
> -----BEGIN PGP SIGNATURE-----
> Version: GnuPG v1.4.15 (Darwin)
> Comment: GPGTools - http://gpgtools.org
> Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
>
> iQIcBAEBCAAGBQJSjPhBAAoJEBzwKT+lPKRYQxIQAMHi+9z9jCbzulHiXns/Mt3p
> J6w6K6nFCbDOgj7noYfwGf2eBINPQ77ywhF56pzBgn6v2wXWG21NRXTLfHxJJM/s
> i1Ol9qp9mEUz3gmcumHbXU+RBBn1CbSh6D8cdVZDsX6tGF4BuzNtseZ0PRq7ZI5A
> fi6dyPA5sZf1skfHIOBhmWT7VB7UGud03YmxnKhe3e7N2ZtDN2AJYNhU0haSHd1m
> 1DGlCYxmMlK5mbqRA3RGWFTrnDmEvhBnSTLJaLywAojN8XHnNAH4fx4+MCT5GXrV
> h1EL1PhvFnpbQ5haTOHNIwCNtW3OPwdLsXXVimOVF6UvEZepF3pDJUL0KVV+Kfem
> p+r5BjkcjZ7LYirDBPFCsIovSwFcLrLScPUKbDHhF0Re5E7K7EtXuVuGGCJqWRsf
> 8w8Z2pcyBIhX85+D+kBZ2m6MFODXnEqTQeGbFhzffuPXV/DuvipARpFg9s8uo1ws
> 85NEtFzHjNblgxVxFaEgbbWulKT1ZNZerAMRnGDh9W2ngMjwYuQfevbJghUkM5b4
> nMc/aNU2mg10lneRwTUIJ0f/aGfiCQegjSSEYGIDi1LcDHDkI4GPmMz3gGIfItBs
> yBEWXKn8aqVqVEVKjFzq5tD0kw9zyCEErYJH6N7o0HYmHHYfPxgz5Cr8gnnayUac
> Ru2Z7Ur1lnZZnC72oUwz
> =bJFf
> -----END PGP SIGNATURE-----
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat connection pool "bleeding" under heavy load

Posted by marko lugarič <ma...@gmail.com>.
Hi

I guess i should code something like start i.e. 50 (configurable parameter
to
increase the load) threads and issues queries non stop over jdbc to i.e. 2
database test tables - we should generate enough trasactions to take all
pool
connections. And I should probably use jdbc connections as defined in
http://tomcat.apache.org/tomcat-7.0-doc/jndi-datasource-examples-howto.htmlsection
Random Connection Closed Exceptions.
Does this seem like good design?

regards, Marko


On Wed, Nov 20, 2013 at 6:58 PM, Christopher Schultz <
chris@christopherschultz.net> wrote:

> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
>
> Marko,
>
> On 11/20/13, 12:07 PM, marko lugarič wrote:
> > I have repeated the test with logAbandoned set to "true" and left
> > it half hour after pool is empty. There are a lot of exceptions
> > (Pool empty. Unable to fetch a connection in 15 seconds and Pool
> > wait interrupted) but i don't know what exactly to search (search
> > with Abandoned did not produce anything). I have already tried
> > using StatementFinalizer interceptor but it did not do anything to
> > prevent pool from being empty.
>
> Can you work-up a simple testcase webapp and load test to reproduce
> this problem? If so, please file a bug against tomcat-pool in Bugzilla
> and attach the simple webapp and test harness.
>
> - -chris
> -----BEGIN PGP SIGNATURE-----
> Version: GnuPG v1.4.15 (Darwin)
> Comment: GPGTools - http://gpgtools.org
> Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
>
> iQIcBAEBCAAGBQJSjPhBAAoJEBzwKT+lPKRYQxIQAMHi+9z9jCbzulHiXns/Mt3p
> J6w6K6nFCbDOgj7noYfwGf2eBINPQ77ywhF56pzBgn6v2wXWG21NRXTLfHxJJM/s
> i1Ol9qp9mEUz3gmcumHbXU+RBBn1CbSh6D8cdVZDsX6tGF4BuzNtseZ0PRq7ZI5A
> fi6dyPA5sZf1skfHIOBhmWT7VB7UGud03YmxnKhe3e7N2ZtDN2AJYNhU0haSHd1m
> 1DGlCYxmMlK5mbqRA3RGWFTrnDmEvhBnSTLJaLywAojN8XHnNAH4fx4+MCT5GXrV
> h1EL1PhvFnpbQ5haTOHNIwCNtW3OPwdLsXXVimOVF6UvEZepF3pDJUL0KVV+Kfem
> p+r5BjkcjZ7LYirDBPFCsIovSwFcLrLScPUKbDHhF0Re5E7K7EtXuVuGGCJqWRsf
> 8w8Z2pcyBIhX85+D+kBZ2m6MFODXnEqTQeGbFhzffuPXV/DuvipARpFg9s8uo1ws
> 85NEtFzHjNblgxVxFaEgbbWulKT1ZNZerAMRnGDh9W2ngMjwYuQfevbJghUkM5b4
> nMc/aNU2mg10lneRwTUIJ0f/aGfiCQegjSSEYGIDi1LcDHDkI4GPmMz3gGIfItBs
> yBEWXKn8aqVqVEVKjFzq5tD0kw9zyCEErYJH6N7o0HYmHHYfPxgz5Cr8gnnayUac
> Ru2Z7Ur1lnZZnC72oUwz
> =bJFf
> -----END PGP SIGNATURE-----
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
>

Re: Tomcat connection pool "bleeding" under heavy load

Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Marko,

On 11/20/13, 12:07 PM, marko lugarič wrote:
> I have repeated the test with logAbandoned set to "true" and left
> it half hour after pool is empty. There are a lot of exceptions
> (Pool empty. Unable to fetch a connection in 15 seconds and Pool
> wait interrupted) but i don't know what exactly to search (search
> with Abandoned did not produce anything). I have already tried
> using StatementFinalizer interceptor but it did not do anything to
> prevent pool from being empty.

Can you work-up a simple testcase webapp and load test to reproduce
this problem? If so, please file a bug against tomcat-pool in Bugzilla
and attach the simple webapp and test harness.

- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (Darwin)
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBCAAGBQJSjPhBAAoJEBzwKT+lPKRYQxIQAMHi+9z9jCbzulHiXns/Mt3p
J6w6K6nFCbDOgj7noYfwGf2eBINPQ77ywhF56pzBgn6v2wXWG21NRXTLfHxJJM/s
i1Ol9qp9mEUz3gmcumHbXU+RBBn1CbSh6D8cdVZDsX6tGF4BuzNtseZ0PRq7ZI5A
fi6dyPA5sZf1skfHIOBhmWT7VB7UGud03YmxnKhe3e7N2ZtDN2AJYNhU0haSHd1m
1DGlCYxmMlK5mbqRA3RGWFTrnDmEvhBnSTLJaLywAojN8XHnNAH4fx4+MCT5GXrV
h1EL1PhvFnpbQ5haTOHNIwCNtW3OPwdLsXXVimOVF6UvEZepF3pDJUL0KVV+Kfem
p+r5BjkcjZ7LYirDBPFCsIovSwFcLrLScPUKbDHhF0Re5E7K7EtXuVuGGCJqWRsf
8w8Z2pcyBIhX85+D+kBZ2m6MFODXnEqTQeGbFhzffuPXV/DuvipARpFg9s8uo1ws
85NEtFzHjNblgxVxFaEgbbWulKT1ZNZerAMRnGDh9W2ngMjwYuQfevbJghUkM5b4
nMc/aNU2mg10lneRwTUIJ0f/aGfiCQegjSSEYGIDi1LcDHDkI4GPmMz3gGIfItBs
yBEWXKn8aqVqVEVKjFzq5tD0kw9zyCEErYJH6N7o0HYmHHYfPxgz5Cr8gnnayUac
Ru2Z7Ur1lnZZnC72oUwz
=bJFf
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat connection pool "bleeding" under heavy load

Posted by marko lugarič <ma...@gmail.com>.
Hello

I have repeated the test with logAbandoned set to "true" and left it half
hour
after pool is empty. There are a lot of exceptions (Pool empty. Unable to
fetch a connection in 15 seconds and Pool wait interrupted) but i don't
know what
exactly to search (search with Abandoned did not produce anything).
I have already tried using StatementFinalizer interceptor but it did not
do anything to prevent pool from being empty.

regards, marko




On Wed, Nov 20, 2013 at 2:28 PM, Christopher Schultz <
chris@christopherschultz.net> wrote:

> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
>
> Marko,
>
> On 11/20/13, 8:14 AM, marko lugarič wrote:
> > Hello
> >
> > The tests are run in the following manner: around 5 min to start
> > the server and connect all clients. Then I can apply load from
> > clients: on the graph I applied only half load for first seven
> > minutes an then full load but this is not required - I can go with
> > full load after all clients connect. So once full load is applied
> > usually in less then 5 minutes pool has no connections (it) - then
> > I can leave it for half hour (tested today) and nothing changes (0
> > empty and zero active connections). But i didn't have logAbandonded
> > set - I can test this too if you think there will be difference. In
> > the usual test when i saw that there is no connections I turned off
> > server (2 - 5 minutes later).
>
> Having logAbandoned set to "true" is pretty critical, here. Please
> re-enabled it and re-test.
>
> In a separate thread, markt pointed out that Tomcat-pool allows you to
> leak resources much more readily than the dbcp-based pool if you don't
> exercise proper resource management. I posted a link to my old blog
> post on the subject, and I'll post it here again as well:
>
>
> http://blog.christopherschultz.net/index.php/2009/03/16/properly-handling-pooled-jdbc-connections/
>
> If you have sloppy JDBC resource management, you are going to waste
> resources on both the client and the server unless you have a pool
> that spends inordinate resources tracking everything to clean up after
> your sloppy code.
>
> Tomcat-pool has a StatementFinalizer interceptor
> (
> http://tomcat.apache.org/tomcat-7.0-doc/jdbc-pool.html#org.apache.tomcat.jdbc.pool.interceptor.StatementFinalizer
> )
> that you can use to help clean-up the messes that you create.
>
> It would be better, though, to clean-up your resources.
>
> Dan Mikasa suggested using a tool like Findbugs on your code, which
> easily identifies things like potential leaks in JDBC resources. It's
> well worth the time to download and run it. (Besides, all you need is
> a JAR file with your code and you can just say "scan the JAR file for
> bugs". It does not require a great deal of setup).
>
> - -chris
> -----BEGIN PGP SIGNATURE-----
> Version: GnuPG v1.4.15 (Darwin)
> Comment: GPGTools - http://gpgtools.org
> Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
>
> iQIcBAEBCAAGBQJSjLjpAAoJEBzwKT+lPKRYdh8QAKuJ95EY3YktG0GsM+Vp/PYK
> P3y4t88ImLtWYIWo2mfeAUaY5sh371yC8ihGcy2m6d/qv+s+lfWpKf/MlaOycvBk
> 5203PRPvSSDI9Tlh19IA6/9urf6YsXDcw62j7X6oOoTQN2GoilhovIl7jUPcTc2M
> dqizRvJDmsWJMODeL0E1Ne1P84AnilNhELL6RPJ09UXYAsbyyFZasALAiwuCXyyt
> fRblQ4pHMTWWK6e7Hrhp93iK9gE1FGtPoQISq9T2GsazzHr8aFavCthFYq03mzRf
> WOYrq1lZsycJKgu0+7xm9xv4KCCVbJX/wCyVVuuhF4s/sZWRioWDyAhn3tx88sFM
> 60u5L95y7zVbxlszE7lmq83B5eyX+3llMIDol32r+T7nJhOo45asyAwOJkF5n8n/
> UQFJhl16I5KTnklq0IM1lol5oDjI9qt+wcqolfUD0FWL7Z5IYFnCpNpo9/9kW+gc
> UNbIbHEm1fOW7bWbpD9KtzLraRLzRS/H9EeVMRr/DRKlna79RYnhi/ErntJrg2cD
> CzaGRq4y+f7ZkyUmArHio6SpifiQeYUgAhwsP6MH9hxNFleoIDa+Xdp4u4Li8RcM
> yM8lNRPLw+mo2fultaA8iYRLVWcul/GbJajUbKEwZh0bV/pVAqPU40U5YuAiEnUc
> qBtkr4U+Lms008/vnc01
> =4seS
> -----END PGP SIGNATURE-----
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
>

Re: Tomcat connection pool "bleeding" under heavy load

Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Marko,

On 11/20/13, 8:14 AM, marko lugarič wrote:
> Hello
> 
> The tests are run in the following manner: around 5 min to start
> the server and connect all clients. Then I can apply load from
> clients: on the graph I applied only half load for first seven
> minutes an then full load but this is not required - I can go with
> full load after all clients connect. So once full load is applied
> usually in less then 5 minutes pool has no connections (it) - then 
> I can leave it for half hour (tested today) and nothing changes (0
> empty and zero active connections). But i didn't have logAbandonded
> set - I can test this too if you think there will be difference. In
> the usual test when i saw that there is no connections I turned off
> server (2 - 5 minutes later).

Having logAbandoned set to "true" is pretty critical, here. Please
re-enabled it and re-test.

In a separate thread, markt pointed out that Tomcat-pool allows you to
leak resources much more readily than the dbcp-based pool if you don't
exercise proper resource management. I posted a link to my old blog
post on the subject, and I'll post it here again as well:

http://blog.christopherschultz.net/index.php/2009/03/16/properly-handling-pooled-jdbc-connections/

If you have sloppy JDBC resource management, you are going to waste
resources on both the client and the server unless you have a pool
that spends inordinate resources tracking everything to clean up after
your sloppy code.

Tomcat-pool has a StatementFinalizer interceptor
(http://tomcat.apache.org/tomcat-7.0-doc/jdbc-pool.html#org.apache.tomcat.jdbc.pool.interceptor.StatementFinalizer)
that you can use to help clean-up the messes that you create.

It would be better, though, to clean-up your resources.

Dan Mikasa suggested using a tool like Findbugs on your code, which
easily identifies things like potential leaks in JDBC resources. It's
well worth the time to download and run it. (Besides, all you need is
a JAR file with your code and you can just say "scan the JAR file for
bugs". It does not require a great deal of setup).

- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (Darwin)
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBCAAGBQJSjLjpAAoJEBzwKT+lPKRYdh8QAKuJ95EY3YktG0GsM+Vp/PYK
P3y4t88ImLtWYIWo2mfeAUaY5sh371yC8ihGcy2m6d/qv+s+lfWpKf/MlaOycvBk
5203PRPvSSDI9Tlh19IA6/9urf6YsXDcw62j7X6oOoTQN2GoilhovIl7jUPcTc2M
dqizRvJDmsWJMODeL0E1Ne1P84AnilNhELL6RPJ09UXYAsbyyFZasALAiwuCXyyt
fRblQ4pHMTWWK6e7Hrhp93iK9gE1FGtPoQISq9T2GsazzHr8aFavCthFYq03mzRf
WOYrq1lZsycJKgu0+7xm9xv4KCCVbJX/wCyVVuuhF4s/sZWRioWDyAhn3tx88sFM
60u5L95y7zVbxlszE7lmq83B5eyX+3llMIDol32r+T7nJhOo45asyAwOJkF5n8n/
UQFJhl16I5KTnklq0IM1lol5oDjI9qt+wcqolfUD0FWL7Z5IYFnCpNpo9/9kW+gc
UNbIbHEm1fOW7bWbpD9KtzLraRLzRS/H9EeVMRr/DRKlna79RYnhi/ErntJrg2cD
CzaGRq4y+f7ZkyUmArHio6SpifiQeYUgAhwsP6MH9hxNFleoIDa+Xdp4u4Li8RcM
yM8lNRPLw+mo2fultaA8iYRLVWcul/GbJajUbKEwZh0bV/pVAqPU40U5YuAiEnUc
qBtkr4U+Lms008/vnc01
=4seS
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat connection pool "bleeding" under heavy load

Posted by marko lugarič <ma...@gmail.com>.
Hello

The tests are run in the following manner: around 5 min to start the server
and connect all clients. Then I can apply load from clients: on the graph
I applied only half load for first seven minutes an then full load but this
is
not required - I can go with full load after all clients connect. So once
full load is
applied usually in less then 5 minutes pool has no connections (it) - then
I can
leave it for half hour (tested today) and nothing changes (0 empty and zero
active connections). But i didn't have logAbandonded set - I can test this
too
if you think there will be difference. In the usual test when i saw that
there is no
connections I turned off server (2 - 5 minutes later).



On Wed, Nov 20, 2013 at 2:35 AM, Christopher Schultz <
chris@christopherschultz.net> wrote:

> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
>
> Marko,
>
> On 11/19/13, 10:16 AM, marko lugarič wrote:
> > About using useEquals="false" property I guess we defined when we
> > started using this pool. After reading the documentation i guess it
> > is better to leave it out (it has no effect on the test - i tested
> > it).
>
> Okay. Let me know if you discover a reason to set that option again.
>
> > We dont have long running queries because there is not much data
> > and all operations are fast (the longest one are ranging from 1 to
> > 2 seconds: i used slowqueryinterceptor and sql server profiler).
> > The test always starts with empty database.
>
> Ok.
>
> > I never got any abandoned messages in the stdout or catalina.out
> > (logabandoned set to true) - I put everything that is not from our
> > application and is at least on INFO level to catalina.out. I added
> > org.apache.tomcat.jdbc.pool package to logs on TRACE level and the
> > only line that is repeating (5 times) is: 2013-11-19 15:25:24,764
> > DEBUG [main] org.apache.tomcat.jdbc.pool.PooledConnection
> > connectUsingDriver(): Instantiating driver using class:
> > com.microsoft.sqlserver.jdbc.SQLServerDriver
> > [url=jdbc:sqlserver://*****;databaseName=chiTestDB]
>
> That will be filling the pool. It's clear that the pool is emptying
> and never re-filling, or you'd get more of the above messages.
>
> > Dont know if there is really that little logging in connection
> > pool. In that case debugging looks like the only option?
>
> Perhaps, but I think you might be able to get more information from
> the pool.
>
> > About C3P0 pool:we are under the impression that
> > org.apache.tomcat.jdbc.pool is the only way to go (production
> > quality) after reading The Tomcat JDBC Connection Pool page (after
> > your comment i guess this is not true and commons-dbcp is
> > production quality alternative?).
>
> IMO the Tomcat-pool documentation overstates the awfulness of the
> dbcp-based pool. We use it for production and it works just fine.
> We've never had a problem with the pool that we didn't cause by our
> own bad webapp code (e.g. not returning connections) or due to
> long-running queries triggering the "abandoned" alarms. OTOH, our site
> does not run an enormously-high transaction rate, either.
>
> > So since this did not work for us we started looking for
> > alternative and C3P0 pooped up in connection pool comparisons or in
> > some stackoverflow thread.
>
> Just note that C3P0 is self-described "beta" software.
>
> So, back to the problem: how long does your test run? Do you allow the
> server to cool-down after your tests? I'm wondering if you are
> shutting-down the server before it has a chance to complain about the
> abandoned connections.
>
> I've never used Tomcat-pool, so I'm not exactly sure what to expect,
> but the abandoned stuff should probably work exactly as described in
> the documentation, and roughly equivalently to the dbcp-based pool.
>
> - -chris
> -----BEGIN PGP SIGNATURE-----
> Version: GnuPG v1.4.15 (Darwin)
> Comment: GPGTools - http://gpgtools.org
> Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
>
> iQIcBAEBCAAGBQJSjBHIAAoJEBzwKT+lPKRYQ4AQALKwD6/Cko6t7di8oXZS8sKO
> pdHc2AQhrPbg95stygZiBm8lH4ds7RhwslD7JcWafSUfln/smLJO0gaV+M3PNDzX
> gQs/zqZyHtEW4vD2oIiL+CY/I0kbAON3tRbXFBjfJKikeINiIrTYGvm8h2dkhq4X
> WLijKrsh/qy96RkmUYPd0o1RsmraYCeGdSNpA96vycgrb89YHiJj07BkinKdhxTQ
> 903huox7ZspSGR0bl/+zEchHKj5AO9D9QELas6Z3qGwd+O7A5rxcX5YHsEXkNX6z
> mTwvAHzobdLXtu7LS6i+td46hFd0QurutnhrOAIZpoHNz7kItRZGDxYB296A5lY/
> xdOzGXKMMaTM854hvLuSPy6zkU2S235+KEA6sVi9HpNtP42yoPbdJfM3thHcKrxB
> Zm/8z6DrMtHFXBRbCFE7PGds9tymCvZx3/n/Zv5a6jm2iSEOLcSSKGnvQG663029
> l2XEGQyZufo+YsY9kQN+zxwSdbBl381PC8YXB+Dh2VR+LYaEuJqpxIkJjR+gIdiT
> JhXm4qSAYVsPDesG7GwXMwY9oFfpVvOzvv8KbH1AM/GaiLBLclTmHWZ8xw+alD7i
> HlR0M9gJ2dw6x6hYbv+wguBksqLxhLFOe+j6rekd7esyMP71nZh4TT4rf+r4XrGe
> 5RkJAULb0vE+ipAgZT/P
> =Vjf7
> -----END PGP SIGNATURE-----
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
>

Re: Tomcat connection pool "bleeding" under heavy load

Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Marko,

On 11/19/13, 10:16 AM, marko lugarič wrote:
> About using useEquals="false" property I guess we defined when we
> started using this pool. After reading the documentation i guess it
> is better to leave it out (it has no effect on the test - i tested
> it).

Okay. Let me know if you discover a reason to set that option again.

> We dont have long running queries because there is not much data
> and all operations are fast (the longest one are ranging from 1 to
> 2 seconds: i used slowqueryinterceptor and sql server profiler).
> The test always starts with empty database.

Ok.

> I never got any abandoned messages in the stdout or catalina.out 
> (logabandoned set to true) - I put everything that is not from our
> application and is at least on INFO level to catalina.out. I added
> org.apache.tomcat.jdbc.pool package to logs on TRACE level and the
> only line that is repeating (5 times) is: 2013-11-19 15:25:24,764
> DEBUG [main] org.apache.tomcat.jdbc.pool.PooledConnection
> connectUsingDriver(): Instantiating driver using class: 
> com.microsoft.sqlserver.jdbc.SQLServerDriver 
> [url=jdbc:sqlserver://*****;databaseName=chiTestDB]

That will be filling the pool. It's clear that the pool is emptying
and never re-filling, or you'd get more of the above messages.

> Dont know if there is really that little logging in connection
> pool. In that case debugging looks like the only option?

Perhaps, but I think you might be able to get more information from
the pool.

> About C3P0 pool:we are under the impression that
> org.apache.tomcat.jdbc.pool is the only way to go (production
> quality) after reading The Tomcat JDBC Connection Pool page (after
> your comment i guess this is not true and commons-dbcp is
> production quality alternative?).

IMO the Tomcat-pool documentation overstates the awfulness of the
dbcp-based pool. We use it for production and it works just fine.
We've never had a problem with the pool that we didn't cause by our
own bad webapp code (e.g. not returning connections) or due to
long-running queries triggering the "abandoned" alarms. OTOH, our site
does not run an enormously-high transaction rate, either.

> So since this did not work for us we started looking for
> alternative and C3P0 pooped up in connection pool comparisons or in
> some stackoverflow thread.

Just note that C3P0 is self-described "beta" software.

So, back to the problem: how long does your test run? Do you allow the
server to cool-down after your tests? I'm wondering if you are
shutting-down the server before it has a chance to complain about the
abandoned connections.

I've never used Tomcat-pool, so I'm not exactly sure what to expect,
but the abandoned stuff should probably work exactly as described in
the documentation, and roughly equivalently to the dbcp-based pool.

- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (Darwin)
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBCAAGBQJSjBHIAAoJEBzwKT+lPKRYQ4AQALKwD6/Cko6t7di8oXZS8sKO
pdHc2AQhrPbg95stygZiBm8lH4ds7RhwslD7JcWafSUfln/smLJO0gaV+M3PNDzX
gQs/zqZyHtEW4vD2oIiL+CY/I0kbAON3tRbXFBjfJKikeINiIrTYGvm8h2dkhq4X
WLijKrsh/qy96RkmUYPd0o1RsmraYCeGdSNpA96vycgrb89YHiJj07BkinKdhxTQ
903huox7ZspSGR0bl/+zEchHKj5AO9D9QELas6Z3qGwd+O7A5rxcX5YHsEXkNX6z
mTwvAHzobdLXtu7LS6i+td46hFd0QurutnhrOAIZpoHNz7kItRZGDxYB296A5lY/
xdOzGXKMMaTM854hvLuSPy6zkU2S235+KEA6sVi9HpNtP42yoPbdJfM3thHcKrxB
Zm/8z6DrMtHFXBRbCFE7PGds9tymCvZx3/n/Zv5a6jm2iSEOLcSSKGnvQG663029
l2XEGQyZufo+YsY9kQN+zxwSdbBl381PC8YXB+Dh2VR+LYaEuJqpxIkJjR+gIdiT
JhXm4qSAYVsPDesG7GwXMwY9oFfpVvOzvv8KbH1AM/GaiLBLclTmHWZ8xw+alD7i
HlR0M9gJ2dw6x6hYbv+wguBksqLxhLFOe+j6rekd7esyMP71nZh4TT4rf+r4XrGe
5RkJAULb0vE+ipAgZT/P
=Vjf7
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat connection pool "bleeding" under heavy load

Posted by marko lugarič <ma...@gmail.com>.
Hello

About using useEquals="false" property I guess we defined when we started
using this pool. After reading the documentation i guess it is better to
leave it
out (it has no effect on the test - i tested it).

We dont have long running queries because there is not much data and all
operations are fast (the longest one are ranging from 1 to 2 seconds: i
used
slowqueryinterceptor and sql server profiler). The test always starts with
empty
database.

I never got any abandoned messages in the stdout or catalina.out
(logabandoned
set to true) - I put everything that is not from our application and is at
least on
INFO level to catalina.out. I added org.apache.tomcat.jdbc.pool package to
logs
on TRACE level and the only line that is repeating (5 times) is:
2013-11-19 15:25:24,764 DEBUG [main]
org.apache.tomcat.jdbc.pool.PooledConnection connectUsingDriver():
Instantiating driver using class:
com.microsoft.sqlserver.jdbc.SQLServerDriver
[url=jdbc:sqlserver://*****;databaseName=chiTestDB]

Dont know if there is really that little logging in connection pool. In
that case
debugging looks like the only option?

About C3P0 pool:we are under the impression that org.apache.tomcat.jdbc.pool
is the only way to go (production quality) after reading The Tomcat JDBC
Connection Pool page (after your comment i guess this is not true and
commons-dbcp is production quality alternative?). So since this did not
work for
us we started looking for alternative and C3P0 pooped up in connection pool
comparisons or in some stackoverflow thread.

regards, Marko


On Mon, Nov 18, 2013 at 11:03 PM, Christopher Schultz <
chris@christopherschultz.net> wrote:

> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
>
> Marko,
>
> On 11/18/13, 3:48 AM, marko lugarič wrote:
> > We have received an issue from our customer that after some time in
> >  production they get empty connection pool. After some time we
> > managed to reproduce their problem in our test environment with
> > smaller number of pool connections.
> >
> > So generally we have a problem that if connection pool is under
> > heavy load (meaning most of the time all the connections are taken
> > - active) it starts to loose database connections (we call it
> > bleed): they are lost from the perspective of Tomcat but they are
> > very much alive when we check then on the database side.
> >
> > We are using Apache Tomcat 7.0.47 running on java 1.6. Database is
> > SQL Server 2008R2 and we are using Hibernate as persistence
> > provider. Our configuration is defined in server.xml in the
> > GlobalNamingResources section (referenced from context.xml):
> >
> > <Resource name="jdbc/ChiDS" auth="Container"
> > type="javax.sql.DataSource"
> > factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"
> > driverClassName="com.microsoft.sqlserver.jdbc.SQLServerDriver"
> > url="jdbc:sqlserver://*****;databaseName=chiTestDB"
> > username="*****" password="*****" initialSize="2" maxActive="5"
> > maxIdle="4" minIdle="2" maxWait="15000"
> > timeBetweenEvictionRunsMillis="30000" testOnBorrow="true"
> > testOnReturn="false" testOnIdle="false" validationQuery="SELECT 1"
> > validationInterval="30000" removeAbandoned="true"
> > removeAbandonedTimeout="60" useEquals="false"/>
>
> I'm just curious: why are you using useEquals="false" here? I've
> wondered what the use-case is for this configuration attribute.
>
> > I will explain in detail what happens. For better understanding I
> > am also providing graph of idle and active connections from Java
> > VisualVM MBeans viewer:
> > http://img11.imageshack.us/img11/6888/fm4j.jpg
> >
> > So we start the server and connect clients to the server that
> > generate small database load. After that we order half of our
> > clients to start generating operations that result in medium
> > database load (I think around 300 transactions per second). We can
> > see from the graph that connection pool is behaving normally
> > (sometimes all 5 connections are taken, sometimes not - if we would
> > run test like this all day everything would be OK). So after 7
> > minutes we increase the load by 100% (other half of clients start
> > to do operations).
> >
> > The load is bigger than 5 pool connections can handle: pretty much
> > all the time all 5 connections are active so we can soon expect
> > that server application logic will start to receive exceptions that
> > jdbc connection is not available (this should happen if application
> > logic does not receive pool connection in 15 seconds). Indeed this
> > happens and the following exception is thrown:
> >
> > Caused by: org.hibernate.exception.GenericJDBCException: Cannot
> > open connection at
> >
> org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
> >
> >
> at
> >
> org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
> >
> >
> at
> >
> org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
> >
> >
> at
> >
> org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
> >
> >
> at
> >
> org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449)
> >
> >
> at
> >
> org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
> >
> >
> at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
> > at
> > org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
> >
> >
> at
> > org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1463)
> >
> >
> at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:60)
> > ... 18 more Caused by: java.sql.SQLException: Pool wait
> > interrupted. at
> >
> org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:655)
> >
> >
> at
> >
> org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:188)
> >
> >
> at
> >
> org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
> >
> >
> at
> >
> org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:92)
> >
> >
> at
> >
> org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
> >
> >
> ... 23 more
> > Caused by: java.lang.InterruptedException at
> >
> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1024)
> >
> >
> at
> >
> java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1303)
> >
> >
> at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:253)
> > at
> >
> org.apache.tomcat.jdbc.pool.FairBlockingQueue.poll(FairBlockingQueue.java:151)
> >
> >
> at
> >
> org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:650)
>
> Good.
> >
> It seems like that is the appropriate result given the situation
> you describe.
>
> > But here something goes wrong because active connections count
> > drops by 1 and never goes back even though database load is still
> > the same. Judging from the graph at this moment pool is giving only
> > 4 pool connections to the application. Pretty soon the same
> > exception is thrown again reducing the active pool count by 1. And
> > then very quickly same exception is thrown 3 more times and pool
> > has no active or idle connections. After this another type of
> > exceptions starts to pop in log file:
> >
> > Caused by: javax.persistence.PersistenceException:
> > org.hibernate.exception.GenericJDBCException: Cannot open
> > connection at
> >
> org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1235)
> >
> >
> at
> >
> org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1168)
> >
> >
> at
> >
> org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:1245)
> >
> >
> at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:63)
> > at
> > com.hsl.chi.persistence.dao.jpa.DAO.beginEntityTransaction(DAO.java:1505)
> >
> >
> at
> > com.hsl.chi.persistence.dao.jpa.DAO.beginFirstSubOperation(DAO.java:992)
> >
> >
> at
> >
> com.hsl.chi.persistence.dao.jpa.SequenceDAO.internalResetSequence(SequenceDAO.java:568)
> >
> >
> ... 9 more
> > Caused by: org.hibernate.exception.GenericJDBCException: Cannot
> > open connection at
> >
> org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
> >
> >
> at
> >
> org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
> >
> >
> at
> >
> org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
> >
> >
> at
> >
> org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
> >
> >
> at
> >
> org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449)
> >
> >
> at
> >
> org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
> >
> >
> at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
> > at
> > org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
> >
> >
> at
> > org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1463)
> >
> >
> at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:60)
> > ... 12 more Caused by:
> > org.apache.tomcat.jdbc.pool.PoolExhaustedException:
> > [[ProtocolHandler]-[pool-1-thread-113]] Timeout: Pool empty. Unable
> > to fetch a connection in 15 seconds, none available[size:5; busy:0;
> > idle:0; lastwait:15000]. at
> >
> org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:674)
> >
> >
> at
> >
> org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:188)
> >
> >
> at
> >
> org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
> >
> >
> at
> >
> org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:92)
> >
> >
> at
> >
> org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
> >
> >  So from the Tomcat point of view we have no jdbc connections to
> > the database in the pool. From this point no database operation
> > can succeed: even if load is reduced to minimum - every database
> > operation fails from application. Then we check the database side:
> > SQL server creates its internal process for each jdbc connection:
> > we can see all 5 connections much alive doing nothing.
> >
> > Since we are using hibernate we were quickly able to do the same
> > test on PostgreSQL database and identical scenario happens:
> > PostgreSQL shows 5 idle processes while pool is empty. The only
> > thing we can do here is to restart the Tomcat.
> >
> > We also tried other configurations (Tomcat 7.0.32, hibernate
> > library was updated to latest version, we used PostgreSQL server
> > instead of SQL server) and different connection pool properties but
> > without any success - we always end up with empty pool. Tomcat
> > properties that we tried:
> >
> > logAbandoned="true" - did not log anything (I guess stack trace
> > should be thrown to console, log file if connection would not be
> > closed from application?), so I guess hibernate is closing
> > connections properly (we are always calling entity manager close
> > method when we finish).
>
> Hibernate should be doing the right thing and always returning
> connections to the pool. I think you can rely on that. However, if you
> have long-running SQL queries, you might be hitting that abandoned
> timeout. Are there any long-running queries in your transactions?
>
> You have timeBetweenEvictionRunsMillis set quite high: abandoned
> connections won't be detected for maybe 30 seconds after they have
> actually been abandoned. For your configuration, that may be 60 + 30 =
> 90 seconds after the connection was last used that you will get any
> kind of error in the logs.
>
> > jdbcInterceptors="StatementFinalizer;SlowQueryReportJmx(threshold=10000)"
> > - statement finalizier did not help
> >
> > testOnReturn="true", testOnIdle="true",
> > propagateInterruptState="true" - did not help
> >
> >
> > So the last option was to change connection pool: we used C3P0
> > connection pool with properties that are similar in meaning as
> > Tomcat ones.
>
> (How come everyone runs to C3P0 when things don't work in Tomcat!?
> There are 2 pools available in Tomcat without having to download beta
> software. Did you try commons-pool, which is currently the default pool?)
>
> > We repeated the above test case and it is working correctly. We
> > have left it with full load half an hour in which we get a lot of
> > exceptions that application did not receive connection but pool is
> > still working OK (all connections are active almost all the time).
> > Exception that is being thrown:
> > com.mchange.v2.resourcepool.BasicResourcePool@437ff0 -- an attempt
> > to checkout a resource was interrupted, and the pool is still live:
> > some other thread must have either interrupted the Thread
> > attempting checkout! java.lang.InterruptedException . Then we
> > reduce the load and exceptions are soon gone since 5 connection can
> > handle them. Here is the configuration from server.xml for C3P0:
> >
> > <Resource name="jdbc/ChiDS" auth="Container"
> > type="com.mchange.v2.c3p0.ComboPooledDataSource"
> > dataSourceName="jdbc/ChiDS"
> > factory="org.apache.naming.factory.BeanFactory"
> > driverClass="com.microsoft.sqlserver.jdbc.SQLServerDriver"
> > jdbcUrl="jdbc:sqlserver://*****;databaseName=chiDB" user="*****"
> > password="*****" initialPoolSize="2" minPoolSize="2"
> > maxPoolSize="5" preferredTestQuery="SELECT 1"
> > testConnectionOnCheckin="true" idleConnectionTestPeriod="30"
> > numHelperThreads="5"/>
> >
> > Currently our customer raised maxActive to bigger number but i
> > guess this will not do once they will start increasing the number
> > of clients (our application has big amount of transactions) and
> > they will have to change connection pool. Are there any additional
> > configuration setting I can try on Tomcat connection pool,
> > otherwise this looks like a bug?
>
> Can you confirm that, during your load tests, you never got any
> "abandoned" messages on the console (stdout, catalina.out, etc.)? Have
> you modified the logging configuration to eliminate such messages?
>
> I'm surprised that the pool is drying up without anything in the logs.
> Can you raise the log level on the pool to DEBUG and re-run your load
> test?
>
> - -chris
> -----BEGIN PGP SIGNATURE-----
> Version: GnuPG v1.4.15 (Darwin)
> Comment: GPGTools - http://gpgtools.org
> Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
>
> iQIcBAEBCAAGBQJSio6kAAoJEBzwKT+lPKRYq0AQAKapJHdErG0qyP586EyVYpNG
> Q25cBTvZskelDPL6FXBfh16p6ZfvrCnH7KYwxucoOv7RHw4F7tA4UEGMYx0q6hbv
> VOho/NA5bDPE4fRHYN1Hif/uHIK8GlsNznFhJz91llxP8fLRykTtOZ2E6NKhztWK
> M/qlW/DxAe/A1KAe46vO4XOzpzIa9dpfLhfGwh0J+n+efj+9ssVz52tmaHMso6tv
> z4RLQcxVI/kDVSBE2y4p2kvZwhYKpHP7RTq9mhLK7U1SywfMdxNeMXAMy0E9jFRp
> eukHfl4o4aUqtym1lYSWc/qPSO1svd2DGIUX6m/Z7X9t3V46gZIm0XXa2oEPO6am
> AuUHS48Z9eyeJ0eOedq8qrfkxWFoIPwmJve4j3x7yXd6vGUKBnuIdqdLbH+AVoIW
> fs/EN2uoupaLt9/U2XoeeQxIlHnAHAZeid+/5zssYyrjxNZrqMAHAIoIC6amZnN6
> WXncOPAG2ni8wIy0hESVpEggf2a4Lgbl7yg/R+akHxjyUCSjiyUo4+zH/5XrfyT5
> DfrvhVxpBpA6SPUCMjQKjTo41FO0Sb+bHe91qDQm7Ajp3ms7RTK4imn9O9ofOuVh
> w9DBVC6oT/TgwSZToHqkPiAtwdHmltq8k9lC40gFJauL9seO1f3mu3XQiSfjfByL
> 8GCc331YMkhDSmZDgIHB
> =ZdwO
> -----END PGP SIGNATURE-----
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
>

Re: Tomcat connection pool "bleeding" under heavy load

Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Marko,

On 11/18/13, 3:48 AM, marko lugarič wrote:
> We have received an issue from our customer that after some time in
>  production they get empty connection pool. After some time we
> managed to reproduce their problem in our test environment with
> smaller number of pool connections.
> 
> So generally we have a problem that if connection pool is under 
> heavy load (meaning most of the time all the connections are taken
> - active) it starts to loose database connections (we call it
> bleed): they are lost from the perspective of Tomcat but they are
> very much alive when we check then on the database side.
> 
> We are using Apache Tomcat 7.0.47 running on java 1.6. Database is 
> SQL Server 2008R2 and we are using Hibernate as persistence
> provider. Our configuration is defined in server.xml in the 
> GlobalNamingResources section (referenced from context.xml):
> 
> <Resource name="jdbc/ChiDS" auth="Container" 
> type="javax.sql.DataSource" 
> factory="org.apache.tomcat.jdbc.pool.DataSourceFactory" 
> driverClassName="com.microsoft.sqlserver.jdbc.SQLServerDriver" 
> url="jdbc:sqlserver://*****;databaseName=chiTestDB" 
> username="*****" password="*****" initialSize="2" maxActive="5" 
> maxIdle="4" minIdle="2" maxWait="15000" 
> timeBetweenEvictionRunsMillis="30000" testOnBorrow="true" 
> testOnReturn="false" testOnIdle="false" validationQuery="SELECT 1" 
> validationInterval="30000" removeAbandoned="true" 
> removeAbandonedTimeout="60" useEquals="false"/>

I'm just curious: why are you using useEquals="false" here? I've
wondered what the use-case is for this configuration attribute.

> I will explain in detail what happens. For better understanding I
> am also providing graph of idle and active connections from Java
> VisualVM MBeans viewer:
> http://img11.imageshack.us/img11/6888/fm4j.jpg
> 
> So we start the server and connect clients to the server that 
> generate small database load. After that we order half of our
> clients to start generating operations that result in medium
> database load (I think around 300 transactions per second). We can
> see from the graph that connection pool is behaving normally
> (sometimes all 5 connections are taken, sometimes not - if we would
> run test like this all day everything would be OK). So after 7
> minutes we increase the load by 100% (other half of clients start
> to do operations).
> 
> The load is bigger than 5 pool connections can handle: pretty much 
> all the time all 5 connections are active so we can soon expect
> that server application logic will start to receive exceptions that
> jdbc connection is not available (this should happen if application
> logic does not receive pool connection in 15 seconds). Indeed this
> happens and the following exception is thrown:
> 
> Caused by: org.hibernate.exception.GenericJDBCException: Cannot
> open connection at 
> org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
>
> 
at
> org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
>
> 
at
> org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
>
> 
at
> org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
>
> 
at
> org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449)
>
> 
at
> org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
>
> 
at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
> at 
> org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
>
> 
at
> org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1463)
>
> 
at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:60)
> ... 18 more Caused by: java.sql.SQLException: Pool wait
> interrupted. at 
> org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:655)
>
> 
at
> org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:188)
>
> 
at
> org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
>
> 
at
> org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:92)
>
> 
at
> org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
>
> 
... 23 more
> Caused by: java.lang.InterruptedException at 
> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1024)
>
> 
at
> java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1303)
>
> 
at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:253)
> at 
> org.apache.tomcat.jdbc.pool.FairBlockingQueue.poll(FairBlockingQueue.java:151)
>
> 
at
> org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:650)

Good.
> 
It seems like that is the appropriate result given the situation
you describe.

> But here something goes wrong because active connections count
> drops by 1 and never goes back even though database load is still
> the same. Judging from the graph at this moment pool is giving only
> 4 pool connections to the application. Pretty soon the same
> exception is thrown again reducing the active pool count by 1. And
> then very quickly same exception is thrown 3 more times and pool
> has no active or idle connections. After this another type of
> exceptions starts to pop in log file:
> 
> Caused by: javax.persistence.PersistenceException: 
> org.hibernate.exception.GenericJDBCException: Cannot open
> connection at 
> org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1235)
>
> 
at
> org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1168)
>
> 
at
> org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:1245)
>
> 
at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:63)
> at 
> com.hsl.chi.persistence.dao.jpa.DAO.beginEntityTransaction(DAO.java:1505)
>
> 
at
> com.hsl.chi.persistence.dao.jpa.DAO.beginFirstSubOperation(DAO.java:992)
>
> 
at
> com.hsl.chi.persistence.dao.jpa.SequenceDAO.internalResetSequence(SequenceDAO.java:568)
>
> 
... 9 more
> Caused by: org.hibernate.exception.GenericJDBCException: Cannot
> open connection at 
> org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
>
> 
at
> org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
>
> 
at
> org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
>
> 
at
> org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
>
> 
at
> org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449)
>
> 
at
> org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
>
> 
at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
> at 
> org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
>
> 
at
> org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1463)
>
> 
at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:60)
> ... 12 more Caused by:
> org.apache.tomcat.jdbc.pool.PoolExhaustedException: 
> [[ProtocolHandler]-[pool-1-thread-113]] Timeout: Pool empty. Unable
> to fetch a connection in 15 seconds, none available[size:5; busy:0;
> idle:0; lastwait:15000]. at 
> org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:674)
>
> 
at
> org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:188)
>
> 
at
> org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
>
> 
at
> org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:92)
>
> 
at
> org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
>
>  So from the Tomcat point of view we have no jdbc connections to
> the database in the pool. From this point no database operation
> can succeed: even if load is reduced to minimum - every database 
> operation fails from application. Then we check the database side: 
> SQL server creates its internal process for each jdbc connection:
> we can see all 5 connections much alive doing nothing.
> 
> Since we are using hibernate we were quickly able to do the same
> test on PostgreSQL database and identical scenario happens:
> PostgreSQL shows 5 idle processes while pool is empty. The only
> thing we can do here is to restart the Tomcat.
> 
> We also tried other configurations (Tomcat 7.0.32, hibernate
> library was updated to latest version, we used PostgreSQL server
> instead of SQL server) and different connection pool properties but
> without any success - we always end up with empty pool. Tomcat
> properties that we tried:
> 
> logAbandoned="true" - did not log anything (I guess stack trace
> should be thrown to console, log file if connection would not be
> closed from application?), so I guess hibernate is closing
> connections properly (we are always calling entity manager close
> method when we finish).

Hibernate should be doing the right thing and always returning
connections to the pool. I think you can rely on that. However, if you
have long-running SQL queries, you might be hitting that abandoned
timeout. Are there any long-running queries in your transactions?

You have timeBetweenEvictionRunsMillis set quite high: abandoned
connections won't be detected for maybe 30 seconds after they have
actually been abandoned. For your configuration, that may be 60 + 30 =
90 seconds after the connection was last used that you will get any
kind of error in the logs.

> jdbcInterceptors="StatementFinalizer;SlowQueryReportJmx(threshold=10000)"
> - statement finalizier did not help
> 
> testOnReturn="true", testOnIdle="true",
> propagateInterruptState="true" - did not help
> 
> 
> So the last option was to change connection pool: we used C3P0 
> connection pool with properties that are similar in meaning as
> Tomcat ones.

(How come everyone runs to C3P0 when things don't work in Tomcat!?
There are 2 pools available in Tomcat without having to download beta
software. Did you try commons-pool, which is currently the default pool?)

> We repeated the above test case and it is working correctly. We
> have left it with full load half an hour in which we get a lot of 
> exceptions that application did not receive connection but pool is 
> still working OK (all connections are active almost all the time). 
> Exception that is being thrown: 
> com.mchange.v2.resourcepool.BasicResourcePool@437ff0 -- an attempt
> to checkout a resource was interrupted, and the pool is still live:
> some other thread must have either interrupted the Thread
> attempting checkout! java.lang.InterruptedException . Then we
> reduce the load and exceptions are soon gone since 5 connection can
> handle them. Here is the configuration from server.xml for C3P0:
> 
> <Resource name="jdbc/ChiDS" auth="Container" 
> type="com.mchange.v2.c3p0.ComboPooledDataSource" 
> dataSourceName="jdbc/ChiDS" 
> factory="org.apache.naming.factory.BeanFactory" 
> driverClass="com.microsoft.sqlserver.jdbc.SQLServerDriver" 
> jdbcUrl="jdbc:sqlserver://*****;databaseName=chiDB" user="*****" 
> password="*****" initialPoolSize="2" minPoolSize="2" 
> maxPoolSize="5" preferredTestQuery="SELECT 1" 
> testConnectionOnCheckin="true" idleConnectionTestPeriod="30" 
> numHelperThreads="5"/>
> 
> Currently our customer raised maxActive to bigger number but i
> guess this will not do once they will start increasing the number
> of clients (our application has big amount of transactions) and
> they will have to change connection pool. Are there any additional 
> configuration setting I can try on Tomcat connection pool,
> otherwise this looks like a bug?

Can you confirm that, during your load tests, you never got any
"abandoned" messages on the console (stdout, catalina.out, etc.)? Have
you modified the logging configuration to eliminate such messages?

I'm surprised that the pool is drying up without anything in the logs.
Can you raise the log level on the pool to DEBUG and re-run your load
test?

- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (Darwin)
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBCAAGBQJSio6kAAoJEBzwKT+lPKRYq0AQAKapJHdErG0qyP586EyVYpNG
Q25cBTvZskelDPL6FXBfh16p6ZfvrCnH7KYwxucoOv7RHw4F7tA4UEGMYx0q6hbv
VOho/NA5bDPE4fRHYN1Hif/uHIK8GlsNznFhJz91llxP8fLRykTtOZ2E6NKhztWK
M/qlW/DxAe/A1KAe46vO4XOzpzIa9dpfLhfGwh0J+n+efj+9ssVz52tmaHMso6tv
z4RLQcxVI/kDVSBE2y4p2kvZwhYKpHP7RTq9mhLK7U1SywfMdxNeMXAMy0E9jFRp
eukHfl4o4aUqtym1lYSWc/qPSO1svd2DGIUX6m/Z7X9t3V46gZIm0XXa2oEPO6am
AuUHS48Z9eyeJ0eOedq8qrfkxWFoIPwmJve4j3x7yXd6vGUKBnuIdqdLbH+AVoIW
fs/EN2uoupaLt9/U2XoeeQxIlHnAHAZeid+/5zssYyrjxNZrqMAHAIoIC6amZnN6
WXncOPAG2ni8wIy0hESVpEggf2a4Lgbl7yg/R+akHxjyUCSjiyUo4+zH/5XrfyT5
DfrvhVxpBpA6SPUCMjQKjTo41FO0Sb+bHe91qDQm7Ajp3ms7RTK4imn9O9ofOuVh
w9DBVC6oT/TgwSZToHqkPiAtwdHmltq8k9lC40gFJauL9seO1f3mu3XQiSfjfByL
8GCc331YMkhDSmZDgIHB
=ZdwO
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org