Missing connections in tomcat jdbc connection pool

Question

We just migrated from dbcp to tomcat jdbc connection pooling. We tried the system in load and received the following exception:

java.sql.SQLException: [IA1856] Timeout: Pool empty. Unable to fetch a connection in 1 seconds, none available[size:125; busy:90; idle:0; lastwait:1000].
        at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:632)
        at org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:174)
        at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:124)
        at com.inneractive.model.mappings.BasicPersistenceEntityMapping.getConnection(BasicPersistenceEntityMapping.java:233)
        at com.inneractive.model.mappings.BasicPersistenceEntityMapping.callWithConnection(BasicPersistenceEntityMapping.java:243)
        at com.inneractive.model.mappings.PersistenceEntityMapping.get(PersistenceEntityMapping.java:194)
        at com.inneractive.model.data.client.ClientUtils.GetClientByExamples(ClientUtils.java:353)
        at com.inneractive.client.ExternalAdRingsClientStart.getClientInfoByRequestParametersOrInsert(ExternalAdRingsClientStart.java:1329)
        at com.inneractive.client.ExternalAdRingsClientStart.newClientSession(ExternalAdRingsClientStart.java:245)
        at com.inneractive.simpleM2M.web.SimpleM2MProtocolBean.generateCampaign(SimpleM2MProtocolBean.java:235)
        at com.inneractive.simpleM2M.web.SimpleM2MProtocolBean.generateCampaign(SimpleM2MProtocolBean.java:219)
        at com.inneractive.simpleM2M.web.AdsServlet.doGet(AdsServlet.java:175)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588)
        at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:396)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)

Notice this:

[size:125; busy:90; idle:0; lastwait:1000]

Where are the connections that are not busy? The busy number kept going down after this, but we still didnt manage to get any connections.

Any ideas?

Configuration:

<Resource auth="Container" driverClassName="com.mysql.jdbc.Driver"
                factory="org.apache.tomcat.jdbc.pool.DataSourceFactory" loginTimeout="10000"
                maxActive="35" maxIdle="35" maxWait="1000" name="jdbc/mysql"
                password="-----" testOnBorrow="true" testOnReturn="false" type="javax.sql.DataSource"
                url="jdbc:mysql://localhost:3306/my_db?elideSetAutoCommits=true&amp;useDynamicCharsetInfo=false&amp;rewriteBatchedStatements=true&amp;useLocalSessionState=true&amp;useLocalTransactionState=true&amp;alwaysSendSetIsolation=false&amp;cacheServerConfiguration=true&amp;noAccessToProcedureBodies=true&amp;useUnicode=true&amp;characterEncoding=UTF-8"
                username="root" validationQuery="SELECT 1"/>

env: ubuntu and tomcat 6. db - mysql

Answer 1

Taking a look at the source of ConnectionPool.java you seem to hit this code snippet in the borrowConnection() method:

        //we didn't get a connection, lets see if we timed out
        if (con == null) {
            if ((System.currentTimeMillis() - now) >= maxWait) {
                throw new SQLException("[" + Thread.currentThread().getName()+"] " +
                    "Timeout: Pool empty. Unable to fetch a connection in " + (maxWait / 1000) +
                    " seconds, none available["+busy.size()+" in use].");
            } else {
                //no timeout, lets try again
                continue;
            }
        }

So according to this, your connection is Null.

The value of con is retrieved on the line:

PooledConnection con = idle.poll();

if you track the code, you will see idle is (depending on your configuration, but by default) FairBlockingQueue. You may checkout the implementation for hints.

In general you always have to close ResultSets, Statements, and Connections and used connections should be correctly released back to the pool. Not doing so correctly may result in connections never been closed => never being available again for reuse (connection pool "leaks").

I suggest you construct some detailed logging over the state of the pool and monitor it to isolate the problem.

Some guidelines from Apache for preventing database connection pool leaks:

removeAbandoned="true"

abandoned database connections are removed and recycled

removeAbandonedTimeout="60"

set the number of seconds a database connection has been idle before it is considered abandoned

logAbandoned="true"

log a stack trace of the code which abandoned the database connection resources. Keep in mind that "logging of abandoned Connections adds overhead for every Connection borrow because a stack trace has to be generated."

I still think slightly increasing the maxWait value (1200, 1500, 1700 - just experiment, there will be no difference in the response times from user perspective) will clear those rare cases, in which you still have problems.

Answer 2

"where are the connections that are not busy ?"

It sounds like they've been dropped and for some reason your connection pool isn't trying to reconnect them.

Add this to the URL that you're connecting to:

autoReconnect=true

And add this as a property to the resource should cause dead connections to be reconnected automatically.

validationQuery="SELECT 1"

Also this should allow you to see connections being dropped:

logAbandoned="true"

There's multiple similar questions on stack overflow.

Tomcat connection pooling,idle connections,and connection creation JDBC Connection pool not reopening Connections in tomcat

However it may also be that you're not releasing the connections completely which is the cause of them dying. JDBC MySql connection pooling practices to avoid exhausted connection pool

Answer 3

seems to be a bug in the pool, size variable is incremented, then trying to create connection, but if creation fails... we have size value large and no actual connections in pool - terrible :

    //if we get here, see if we need to create one
    //this is not 100% accurate since it doesn't use a shared
    //atomic variable - a connection can become idle while we are creating
    //a new connection
    if (size.get() < getPoolProperties().getMaxActive()) {
        //atomic duplicate check
        if (size.addAndGet(1) > getPoolProperties().getMaxActive()) {
            //if we got here, two threads passed through the first if
            size.decrementAndGet();
        } else {
            //create a connection, we're below the limit
            return createConnection(now, con, username, password);
        }
    } //end if