Java – Tomcat Connection pool creating too many connections, stuck in sleep mode

connection-poolingjavaMySQLtomcat

I'm using Tomcat 6.0.29, with Tomcat 7's connection pool and MySQL. Testing my application, it doesn't reuse anything from the pool, but ends up creating a new pool, to eventually where I cannot use the database because there are hundreds of sleeping connections in the pool when the max active size for the pool is set to 20.

See here for reference:

+----+------+-----------------+--------+---------+------+-------+------------------+
| Id | User | Host            | db     | Command | Time | State | Info             |
+----+------+-----------------+--------+---------+------+-------+------------------+
|  2 | root | localhost:51877 | dbname | Sleep   |    9 |       | NULL             |
|  4 | root | localhost       | NULL   | Query   |    0 | NULL  | show processlist |
|  5 | root | localhost:49213 | dbname | Sleep   |   21 |       | NULL             |
|  6 | root | localhost:53492 | dbname | Sleep   |   21 |       | NULL             |
|  7 | root | localhost:46012 | dbname | Sleep   |   21 |       | NULL             |
|  8 | root | localhost:34964 | dbname | Sleep   |   21 |       | NULL             |
|  9 | root | localhost:52728 | dbname | Sleep   |   21 |       | NULL             |
| 10 | root | localhost:43782 | dbname | Sleep   |   21 |       | NULL             |
| 11 | root | localhost:38468 | dbname | Sleep   |   21 |       | NULL             |
| 12 | root | localhost:48021 | dbname | Sleep   |   21 |       | NULL             |
| 13 | root | localhost:54854 | dbname | Sleep   |   21 |       | NULL             |
| 14 | root | localhost:41520 | dbname | Sleep   |   21 |       | NULL             |
| 15 | root | localhost:38112 | dbname | Sleep   |   13 |       | NULL             |
| 16 | root | localhost:39168 | dbname | Sleep   |   13 |       | NULL             |
| 17 | root | localhost:40427 | dbname | Sleep   |   13 |       | NULL             |
| 18 | root | localhost:58179 | dbname | Sleep   |   13 |       | NULL             |
| 19 | root | localhost:40957 | dbname | Sleep   |   13 |       | NULL             |
| 20 | root | localhost:45567 | dbname | Sleep   |   13 |       | NULL             |
| 21 | root | localhost:48314 | dbname | Sleep   |   13 |       | NULL             |
| 22 | root | localhost:34546 | dbname | Sleep   |   13 |       | NULL             |
| 23 | root | localhost:44928 | dbname | Sleep   |   13 |       | NULL             |
| 24 | root | localhost:57320 | dbname | Sleep   |   13 |       | NULL             |
| 25 | root | localhost:54643 | dbname | Sleep   |   29 |       | NULL             |
| 26 | root | localhost:49809 | dbname | Sleep   |   29 |       | NULL             |
| 27 | root | localhost:60993 | dbname | Sleep   |   29 |       | NULL             |
| 28 | root | localhost:36676 | dbname | Sleep   |   29 |       | NULL             |
| 29 | root | localhost:53574 | dbname | Sleep   |   29 |       | NULL             |
| 30 | root | localhost:45402 | dbname | Sleep   |   29 |       | NULL             |
| 31 | root | localhost:37632 | dbname | Sleep   |   29 |       | NULL             |
| 32 | root | localhost:56561 | dbname | Sleep   |   29 |       | NULL             |
| 33 | root | localhost:34261 | dbname | Sleep   |   29 |       | NULL             |
| 34 | root | localhost:55221 | dbname | Sleep   |   29 |       | NULL             |
| 35 | root | localhost:39613 | dbname | Sleep   |   15 |       | NULL             |
| 36 | root | localhost:52908 | dbname | Sleep   |   15 |       | NULL             |
| 37 | root | localhost:56401 | dbname | Sleep   |   15 |       | NULL             |
| 38 | root | localhost:44446 | dbname | Sleep   |   15 |       | NULL             |
| 39 | root | localhost:57567 | dbname | Sleep   |   15 |       | NULL             |
| 40 | root | localhost:56445 | dbname | Sleep   |   15 |       | NULL             |
| 41 | root | localhost:39616 | dbname | Sleep   |   15 |       | NULL             |
| 42 | root | localhost:49197 | dbname | Sleep   |   15 |       | NULL             |
| 43 | root | localhost:59916 | dbname | Sleep   |   15 |       | NULL             |
| 44 | root | localhost:37165 | dbname | Sleep   |   15 |       | NULL             |
| 45 | root | localhost:45649 | dbname | Sleep   |    1 |       | NULL             |
| 46 | root | localhost:55397 | dbname | Sleep   |    1 |       | NULL             |
| 47 | root | localhost:34322 | dbname | Sleep   |    1 |       | NULL             |
| 48 | root | localhost:54387 | dbname | Sleep   |    1 |       | NULL             |
| 49 | root | localhost:55147 | dbname | Sleep   |    1 |       | NULL             |
| 50 | root | localhost:47280 | dbname | Sleep   |    1 |       | NULL             |
| 51 | root | localhost:56856 | dbname | Sleep   |    1 |       | NULL             |
| 52 | root | localhost:58369 | dbname | Sleep   |    1 |       | NULL             |
| 53 | root | localhost:33712 | dbname | Sleep   |    1 |       | NULL             |
| 54 | root | localhost:44315 | dbname | Sleep   |    1 |       | NULL             |
| 55 | root | localhost:54649 | dbname | Sleep   |   14 |       | NULL             |
| 56 | root | localhost:41202 | dbname | Sleep   |   14 |       | NULL             |
| 57 | root | localhost:59393 | dbname | Sleep   |   14 |       | NULL             |
| 58 | root | localhost:38304 | dbname | Sleep   |   14 |       | NULL             |
| 59 | root | localhost:34548 | dbname | Sleep   |   14 |       | NULL             |
| 60 | root | localhost:49567 | dbname | Sleep   |   14 |       | NULL             |
| 61 | root | localhost:48077 | dbname | Sleep   |   14 |       | NULL             |
| 62 | root | localhost:48586 | dbname | Sleep   |   14 |       | NULL             |
| 63 | root | localhost:45308 | dbname | Sleep   |   14 |       | NULL             |
| 64 | root | localhost:43169 | dbname | Sleep   |   14 |       | NULL             |

It creates exactly 10 for each request, which is the minIdle & InitialSize attribute as seen below.

Here is the sample test code embedded into a jsp page. The code is not the code in my application and just used to see if the issue was with my code, but the problem still persisted.

Context envCtx;
envCtx = (Context) new InitialContext().lookup("java:comp/env");
DataSource datasource = (DataSource) envCtx.lookup("jdbc/dbname");
Connection con = null;

try {
  con = datasource.getConnection();
  Statement st = con.createStatement();
  ResultSet rs = st.executeQuery("select * from UserAccount");
  int cnt = 1;
  while (rs.next()) {
      out.println((cnt++)+". Token:" +rs.getString("UserToken")+
        " FirstName:"+rs.getString("FirstName")+" LastName:"+rs.getString("LastName"));
  }
  rs.close();
  st.close();
} finally {
  if (con!=null) try {con.close();}catch (Exception ignore) {}
}

Here is my context.xml file:

<?xml version="1.0" encoding="UTF-8"?>
<Context>
    <Resource name="jdbc/dbname" 
              auth="Container" 
              type="javax.sql.DataSource" 
              factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"
              testWhileIdle="true"
              testOnBorrow="true"
              testOnReturn="false"
              validationQuery="SELECT 1"
              validationInterval="30000"
              timeBetweenEvictionRunsMillis="30000"
              maxActive="20" 
              minIdle="10" 
              maxWait="10000" 
              initialSize="10"
              removeAbandonedTimeout="60"
              removeAbandoned="true"
              logAbandoned="true"
              minEvictableIdleTimeMillis="30000" 
              jmxEnabled="true"
              jdbcInterceptors=
"org.apache.tomcat.jdbc.pool.interceptor.ConnectionState;org.apache.tomcat.jdbc.pool.interceptor.StatementFinalizer"
              username="" 
              password="" 
              driverClassName="com.mysql.jdbc.Driver"
              url="jdbc:mysql://localhost:3306/dbname?autoReconnect=true&amp;useUnicode=true&amp;characterEncoding=utf8"/>

<WatchedResource>WEB-INF/web.xml</WatchedResource>
<WatchedResource>META-INF/context.xml</WatchedResource>
</Context>

I'm sure I can use removeAbandonedTimeout to a low number and it would purge all these sleeping connections, but that wouldn't fix the real problem would it? Does anyone know what I'm doing wrong? Thank you very much.

Best Answer

I don't have an environment to test this in, at the moment, however, I believe that you should be closing your Connection, Statement, and ResultSet after each query; if any of these leak, it could leave the Connection hanging in an idle (but not necessarily returned to the pool) state.

The Connection object you receive should actually be a sort of proxy from the pooling layer; calling close on it releases your "reservation" on that connection and returns it to the pool. (It will not necessarily close the underlying, actual database connection.)

Because it could be remaining open (usually will be), unclosed Statements or ResultSets could be interpreted by the pool layer as an indication of being still “busy.”

You may be able to inspect (e.g. debugger makes this easy) the Connection object to identify its state at run-time, to confirm this.

For simplicity (…) we used the following nasty little routine in the finally blocks after every database connection call: … finally { closeAll (rs, st, con); }, ensuring that they would fall out of context immediately.

    /**
 * Close a bunch of things carefully, ignoring exceptions. The
 * “things” supported, thus far, are:
 * <ul>
 * <li>JDBC ResultSet</li>
 * <li>JDBC Statement</li>
 * <li>JDBC Connection</li>
 * <li>Lock:s</li>
 * </ul>
 * <p>
 * This is mostly meant for “finally” clauses.
 *
 * @param things A set of SQL statements, result sets, and database
 *            connections
 */
public static void closeAll (final Object... things) {
    for (final Object thing : things) {
        if (null != thing) {
            try {
                if (thing instanceof ResultSet) {
                    try {
                        ((ResultSet) thing).close ();
                    } catch (final SQLException e) {
                        /* No Op */
                    }
                }
                if (thing instanceof Statement) {
                    try {
                        ((Statement) thing).close ();
                    } catch (final SQLException e) {
                        /* No Op */
                    }
                }
                if (thing instanceof Connection) {
                    try {
                        ((Connection) thing).close ();
                    } catch (final SQLException e) {
                        /* No Op */
                    }
                }
                if (thing instanceof Lock) {
                    try {
                        ((Lock) thing).unlock ();
                    } catch (final IllegalMonitorStateException e) {
                        /* No Op */
                    }
                }
            } catch (final RuntimeException e) {
                /* No Op */
            }
        }
    }
}

This was just syntactic sugar to ensure that nobody forgot to put in the longer, uglier stanza of if (null != con) { try { con.close () } catch (SQLException e) {} } (usually repeated three times for ResultSet, Statement, and Connection); and removed the "visual noise" of what our formatter would turn into a full screen of incidental cleanup code on every block of code that touched the database.

(The Lock support in there was for some related, but nasty, deadlock states on potential exceptions, that didn't have much to do with the database at all, but we used in a similar way to reduce the line noise in some thread-synchronization code. This is from an MMO server that might have 4,000 active threads at a time trying to manipulate game objects and SQL tables.)

THE SOLUTION (tl;dr)

In order to solve this issue, add an attribute closeMethod (documented here) with the value "close" to the Resource element in the context.xml file.

Here's the correct content of my /META-INF/context.xml file:

<Context>
    <!-- Configuration for the Tomcat JDBC Connection Pool -->
    <Resource name="jdbc/someDB"
        type="javax.sql.DataSource"
        auth="Container"
        factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"
        driverClassName="org.postgresql.Driver"
        url="jdbc:postgresql://localhost:5432/somedb"
        username="postgres"
        password="12345"
        maxActive="100"
        minIdle="10"
        initialSize="10"
        validationQuery="SELECT 1"
        validationInterval="30000"
        removeAbandoned="true"
        removeAbandonedTimeout="60"
        abandonWhenPercentageFull="50"
        closeMethod="close" />
</Context>

Pay attention to the attribute closeMethod. I tested it and now the number of connections are kept STRICTLY as defined in the context.xml file!

NOTE
There is one moment (related to JNDI) that may be taken care of. See the UPDATE 3 for the complete description.

Long answer

OK, I found the above solution thanks to Apache Tomcat committor Konstantin Kolinko. I reported this issue as an Apache Tomcat bug on ASF Bugzilla and ~~it turned out it's not a bug~~ (see UPDATE 1).

=== UPDATE 1 (2012-12-03) aka "A New Hope" ===

Well, it still turned out to be a bug. Mark Thomas, the Apache Tomcat 7 release manager, confirmed that (quote):

"This is a memory leak bug in jdbc-pool. PoolCleaner instances are retaining references to the ConnectionPool preventing it from being GC'd.
...
This has been fixed in trunk and 7.0.x and will be included in 7.0.34 onwards."

So if you have an older Tomcat version (less than 7.0.34), use the above solution, otherwise, ~~starting with Apache Tomcat version 7.0.34, there should be no issues like the one I described.~~ (see UPDATE 2)

=== UPDATE 2 (2014-01-13) aka "The Issue Strikes Back" ===

It seems like the issue initially described in my bug report is still present even for the currently latest Apache Tomcat version 7.0.50 and I also reproduced it with Tomcat 7.0.47 (thanks to Miklos Krivan for pointing it out). Although now Tomcat sometimes manages to close additional connections after reloading, and sometimes the number of connections are increased after one reload and then kept steady, but eventually this behavior is still not reliable.

I still could reproduce the initially described issue (although again not that easy: it may be related to the frequency of successive reloads). Seems like it's just a matter of time, i.e. if Tomcat has enough time after reload, it manages the connection pool more or less as it should. As Mark Thomas mentioned in his comment (quote): "As per the docs for closeMethod, that method exists solely to speed up the freeing of resources that would otherwise be freed by GC." (end of quote), and it looks like the speed is the defining factor.

When using the solution presented by Konstantin Kolinko (to use closeMethod="close") everything WORKS just fine, and the number of connections reserved are kept STRICTLY as defined in the context.xml file. So it appears that using closeMethod="close" is the ONLY true way (at the moment) to avoid running out of connections after context reloading.

=== UPDATE 3 (2014-01-13) aka "Return of the Tomcat Release Manager" ===

The mystery behind the behavior described in the UPDATE 2 is solved. More details have been cleared now after I received a reply from Mark Thomas (Tomcat release manager). I hope this is the last update. So the bug was indeed fixed as was mentioned in the UPDATE 1. I am posting the essential part from Mark's reply here as a quote (emphasis mine):

The actual memory leak found while investigating this bug has been fixed in 7.0.34 onwards as per comments #4 to #6.

The issue of the connections not being closed on reload is a result of the J2EE specification for JNDI resources and this part of the bug report is therefore invalid. I am restoring the state of this bug to fixed to reflect that the memory leak that did exist has been fixed.

To expand on why the failure to immediately close connection after reload is invalid, the J2EE specification provides no mechanism for the container to tell the resource it is no longer required. Therefore all the container can do is clear references to the resource and wait for garbage collection (which will trigger the closure of the pool and the associated connections). Garbage collection occurs at times determined by the JVM so this is why it takes an indeterminate amount of time for connections to be closed after a context reload as a garbage collection may not occur for some time.

Tomcat has added the Tomcat specific JNDI attribute closeMethod which can be used to trigger the explicit close of a JNDI resource when a context is stopped. If waiting for GC to clean up resources is not acceptable then simply use this parameter. Tomcat does not use this by default as it may have unexpected and unwanted side-effects for some JNDI resources.

If you'd like to see a standard mechanism provided for telling JNDI resources that they are no longer required then you need to lobby the J2EE expert group.

Conclusion

Just use the solution presented in the beginning of this post (but, just in case, keep in mind the JNDI related issue that can theoretically arise from using it).

Alternative solution

Michael Osipov suggested using his CloseableResourceListener, which prevents memory leaks caused by left open resources during undeployment of web applications. So you may also give it a try.

DISCLAIMER
The aliases for the UPDATES were inspired by the Star Wars film series. All rights belong to their respective owners.

Best Answer

Related Solutions

Mysql – Missing connections in tomcat jdbc connection pool

Java – JDBC connection pool runs out of connections when Context reload=”true” is enabled in Tomcat

THE SOLUTION (tl;dr)

Long answer

Conclusion

Alternative solution

Related Topic