title: Analyzing Connection Closed Exception in Spring/JPA/Mysql/Tomcat app
body: <p><strong>PROBLEM</strong></p>
  
  <p>I have recently been put in charge of a Java web application with code already written and in place. The app receives moderately high traffic and has peak hours of traffic between 11am to 3pm everyday.
  The application uses Spring, JPA(Hibernate), MYSQL DB. 
  Spring has been configured to use tomcat jdbc connection pool to make connections to the DB. 
  (Details of configuration at the end of the post)</p>
  
  <p>For the past few days, during the application's peak load hours, the application has been going down due to tomcat going unresponsive to requests. It has required tomcat to be restarted multiple times.</p>
  
  <p>Going through the tomcat catalina.out logs, I noticed a whole lot of </p>
  
  <pre><code>Caused by: java.sql.SQLException: Connection has already been closed.
      at org.apache.tomcat.jdbc.pool.ProxyConnection.invoke(ProxyConnection.java:117)
      at org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:109)
      at org.apache.tomcat.jdbc.pool.DisposableConnectionFacade.invoke(DisposableConnectionFacade.java:80)
      at com.sun.proxy.$Proxy28.prepareStatement(Unknown Source)
      at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:505)
      at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:423)
      at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
      at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1547)
      at org.hibernate.loader.Loader.doQuery(Loader.java:673)
      at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
      at org.hibernate.loader.Loader.loadCollection(Loader.java:1994)
      ... 115 more
  </code></pre>
  
  <p>These appear frequently just before the crash.</p>
  
  <p>Going further earlier before these exceptions, I noticed a whole lot of Connections being abandoned just before the Connection Closed exceptions.</p>
  
  <pre><code>WARNING: Connection has been abandoned PooledConnection[com.mysql.jdbc.Connection@543c2ab5]:java.lang.Exception
      at org.apache.tomcat.jdbc.pool.ConnectionPool.getThreadDump(ConnectionPool.java:1065)
      at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:782)
      at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:618)
      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.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:47)
      at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:423)
      at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
      at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
  </code></pre>
  
  <p>These seem to appear frequently just before the Connection Closed exceptions. And these seem to be the first symptoms of impending doom in the logs. </p>
  
  <p><strong>ANALYSIS</strong></p>
  
  <p>Going by the logs, I set out to see if there is any connection pool configuration/mysql configuration that might be causing the issue.
  Went through a couple of excellent articles that show tuning of the pool for Production environment. Links <a href="http://www.tomcatexpert.com/blog/2010/04/01/configuring-jdbc-pool-high-concurrency" rel="noreferrer">1</a> &amp; <a href="http://www.codingpedia.org/ama/tomcat-jdbc-connection-pool-configuration-for-production-and-development/" rel="noreferrer">2</a></p>
  
  <p>Going by these articles, I noticed that:</p>
  
  <ol>
  <li><p>The below line in JHanik's article (link 1) mentions this</p>
  
  <blockquote>
    <p>Setting the value of abandonWhenPercentageFull to 100 would mean that connections are not > considered abandoned unless we've reached our maxActive limit. </p>
  </blockquote>
  
  <p>I figured this might be important in my case, because I see a lot of connections being  abandoned.</p></li>
  <li><p>My max_connections setting does not match what is being recommended (in link 2)</p>
  
  <blockquote>
    <p>mysql max_connections should be equal to max_active+max_idle</p>
  </blockquote></li>
  </ol>
  
  <p><strong>WHAT I TRIED</strong></p>
  
  <p>So, as per the recommendations from the articles, I did the following two things:</p>
  
  <ol>
  <li>Changed abandonWhenPercentageFull to 100</li>
  <li>In my MYSQL server, max_connections was set as 500. Increased it to 600
     In my connection pool settings, max_active was 200 and max_idle was 50. 
     Changed it to max_active=350, max_idle = 250</li>
  </ol>
  
  <p><strong>THIS DID NOT HELP</strong></p>
  
  <p>The next day, the following observations were made during peak hours:</p>
  
  <ol>
  <li>Tomcat did not go down. The app stayed up throughout peak hours. 
  However the performance went from bad to worse and then the app was barely usable even though it did not really go down. </li>
  <li>DB Connection pool, though increased in size, got completely utilized, and I could see 350 active connections to the DB at one point.</li>
  </ol>
  
  <p><strong>FINALLY, MY QUESTION:</strong></p>
  
  <p>It clearly looks like there are issues with the way DB connections are being made from the app server.
  So I have two directions to take this analysis forward. </p>
  
  <p>My question is which of these should I be taking?</p>
  
  <p><strong>1. The issue is not with the connection pool settings. The code is what is causing the issue</strong></p>
  
  <p>There might be places in the code where DB connections are not being closed. Which is causing the high number of connections being open.</p>
  
  <p>The code uses a GenericDao which is extended in every Dao class. The GenericDao uses Spring's JpaTemplate to fetch a EntityManager instance which in turn is used for all DB operations. My understanding is using the JpaTemplate handles the nitty gritty of closing DB connections internally.  </p>
  
  <p>So, where exactly should I looking for possible connection leaks?</p>
  
  <p><strong>2. The issue is with the connections pool/mysql config parameters. However, the optimizations I have put in need to be tuned further</strong></p>
  
  <p>If yes, which parameters should I be looking at? 
     Should I be collecting some data to use to determine more appropriate values for my   connection pool. (For eg, for max_active, max_idle, max_connections)</p>
  
  <hr>
  
  <p><em>Addendum: Complete Connection Pool configuration</em></p>
  
  <pre><code>   &lt;bean id="dataSource" class="org.apache.tomcat.jdbc.pool.DataSource" destroy-method="close"&gt;
          &lt;property name="driverClassName" value="com.mysql.jdbc.Driver" /&gt;
          &lt;property name="url" value="jdbc:mysql://xx.xx.xx.xx" /&gt;
          &lt;property name="username" value="xxxx" /&gt;
          &lt;property name="password" value="xxxx" /&gt;
          &lt;property name="initialSize" value="10" /&gt;
          &lt;property name="maxActive" value="350" /&gt;
          &lt;property name="maxIdle" value="250" /&gt;
          &lt;property name="minIdle" value="90" /&gt;
          &lt;property name="timeBetweenEvictionRunsMillis" value="30000" /&gt;
          &lt;property name="removeAbandoned" value="true" /&gt;
          &lt;property name="removeAbandonedTimeout" value="60" /&gt;
          &lt;property name="abandonWhenPercentageFull" value="100" /&gt;
          &lt;property name="testOnBorrow" value="true" /&gt;
          &lt;property name="validationQuery" value="SELECT 1" /&gt;
          &lt;property name="validationInterval" value="30000" /&gt;
          &lt;property name="logAbandoned" value="true" /&gt;
          &lt;property name="jmxEnabled" value="true" /&gt;
      &lt;/bean&gt;
  </code></pre>