title: trying to find db connection leak in my code, using Spring / JPA / Hikari
body: <p>I've got a problem with a Spring web application that periodically runs into an error fetching a connection from my connection pool. Eventually in the logs I see entries like:</p>
  
  <ul>
  <li>Caused by: javax.persistence.PersistenceException: org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection</li>
  <li>Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.</li>
  </ul>
  
  <p>Only way to recover I've found once it hits this point is to restart Tomcat.</p>
  
  <p>I think the most likely explanation is I have some code somewhere that is not properly cleaning up its connection - returning it to Hikari, leaving something open so Spring can't clean it up, etc.</p>
  
  <p>To troubleshoot I've set my hikari config leakDetectionThreshold to 5000ms and enabled logging. After that, I see log entries like</p>
  
  <pre><code>2018-04-24 19:53:56 WARN  ProxyLeakTask:87 - Connection leak detection 
  triggered for org.postgresql.jdbc.PgConnection@664ec666, stack trace 
  follows
  java.lang.Exception: Apparent connection leak detected
      at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122)
      at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:35)
      at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:99)
      at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:129)
      at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:47)
      at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:146)
      at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:172)
      at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:148)
      at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1940)
      at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1909)
      at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1887)
      at org.hibernate.loader.Loader.doQuery(Loader.java:932)
      at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:349)
      at org.hibernate.loader.Loader.doList(Loader.java:2615)
      at org.hibernate.loader.Loader.doList(Loader.java:2598)
      at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2430)
      at org.hibernate.loader.Loader.list(Loader.java:2425)
      at org.hibernate.loader.custom.CustomLoader.list(CustomLoader.java:335)
      at org.hibernate.internal.SessionImpl.listCustomQuery(SessionImpl.java:2129)
      at org.hibernate.internal.AbstractSharedSessionContract.list(AbstractSharedSessionContract.java:981)
      at org.hibernate.query.internal.NativeQueryImpl.doList(NativeQueryImpl.java:147)
      at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1398)
      at org.hibernate.query.internal.AbstractProducedQuery.getSingleResult(AbstractProducedQuery.java:1444)
      at sun.reflect.GeneratedMethodAccessor191.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:498)
      at org.springframework.orm.jpa.SharedEntityManagerCreator$DeferredQueryInvocationHandler.invoke(SharedEntityManagerCreator.java:379)
      at com.sun.proxy.$Proxy163.getSingleResult(Unknown Source)
      at com.mycompany.web.jpa.util.DBHelper.getPagedMappedDbResults(DBHelper.java:76)
      at com.mycompany.web.jpa.repository.TaskRepositoryImpl.findTaskDetailsByStepIdAndIdIn(TaskRepositoryImpl.java:245)
  ......
  </code></pre>
  
  <p>So it is detecting a possible leak. Could be a false positive I suppose? But this is also the only class in my app that is doing database access outside of the standard service/repository pattern often used in Spring apps, so it seems like a likely culprit, and it's my best lead at the moment.</p>
  
  <p>Anyway, the last piece of non library code I see in the trace (ie stuff I wrote, so most likely to be the cause of the leak!) is my DBHelper::getPagedMappedDbResults method, relevant bit included here:</p>
  
  <pre><code>    Query q = entityManager.createNativeQuery(countQueryText);
      setQueryParameters(q, parameters);
      long numActualResults = 0;
      try {
          numActualResults = ((Number)q.getSingleResult()).longValue(); // line 76
      } catch (Exception e) {
          System.out.println("just in case: " + e);
      }
  </code></pre>
  
  <p>So basically I create a Query object from my EntityManager instance, set some parameters, and run it to get some results.</p>
  
  <p>Is there something I need to be doing with a Query object when I'm done with it? q.cleanup()? I don't see anything like this from reading the docs, but am I not doing good housekeeping on this resource?</p>
  
  <p>The entityManager itself is created from an @Autowired annotation. My understanding is if I didn't "new" it to instantiate it and instead let the Spring framework autowire it, then Spring will do whatever cleanup is necessary. Is that right? Or do I need to be doing some cleanup after I use the entityManager?</p>
  
  <p>Version details:</p>
  
  <ul>
  <li>Tomcat 8 / Java 8</li>
  <li>Spring 5.0.0.RELEASE</li>
  <li>Spring Data Kay-RELEASE</li>
  <li>Hibernate 5.2.3.Final</li>
  <li>Hikari 2.4.5</li>
  </ul>
  
  <p>Any advice or suggestions would be greatly appreciated, thanks!</p>