Database Connections Are Being Abandoned When They Should Not Be

In our logs we see multiple WARNINGS (see stack trace at the end of this message) that indicated database connections are being abandoned when they should not be.

Our research into this issue indicates that either database connections are not being closed correctly or queries are taking longer then the connection eviction time.

The settings for database connections are here: https://github.com/Jasig/NewsReaderPortlet/blob/master/src/main/webapp/WEB-INF/context/databaseContext.xml

Stack Trace:

14-Sep-2016 14:50:50.198 WARNING [Tomcat JDBC Pool Cleaner[25026199:1473621740197]] org.apache.tomcat.jdbc.pool.ConnectionPool.abandon Connection has been abandoned PooledConnection[oracle.jdbc.driver.T4CConnection@305392e3]:java.lang.Exception
at org.apache.tomcat.jdbc.pool.ConnectionPool.getThreadDump(ConnectionPool.java:1069)
at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:787)
at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:633)
at org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:187)
at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:132)
at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.getConnection(LocalDataSourceConnectionProvider.java:85)
at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:161)
at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1700)
at org.hibernate.loader.Loader.doQuery(Loader.java:801)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:274)
at org.hibernate.loader.Loader.doList(Loader.java:2542)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2276)
at org.hibernate.loader.Loader.list(Loader.java:2271)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:459)
at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:365)
at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:196)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1268)
at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
at org.jasig.portlet.newsreader.dao.HibernateNewsStore.initNews(HibernateNewsStore.java:180)
at sun.reflect.GeneratedMethodAccessor1281.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:201)
at com.sun.proxy.$Proxy373.initNews(Unknown Source)
at org.jasig.portlet.newsreader.service.SharedNewsSetServiceImpl.getNewsSet(SharedNewsSetServiceImpl.java:76)
at org.jasig.portlet.newsreader.mvc.portlet.reader.AjaxNewsController.getJSONFeeds(AjaxNewsController.java:96)
at sun.reflect.GeneratedMethodAccessor1262.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:177)
at org.springframework.web.portlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:369)
at org.springframework.web.portlet.mvc.annotation.AnnotationMethodHandlerAdapter.doHandle(AnnotationMethodHandlerAdapter.java:356)
at org.springframework.web.portlet.mvc.annotation.AnnotationMethodHandlerAdapter.handleResource(AnnotationMethodHandlerAdapter.java:302)
at org.springframework.web.portlet.DispatcherPortlet.doResourceService(DispatcherPortlet.java:859)
at org.springframework.web.portlet.FrameworkPortlet.processRequest(FrameworkPortlet.java:539)
at org.springframework.web.portlet.FrameworkPortlet.serveResource(FrameworkPortlet.java:490)
at org.jasig.portal.portlet.container.FilterChainImpl.doFilter(FilterChainImpl.java:211)
at org.jasig.portal.portlet.container.FilterChainImpl.processFilter(FilterChainImpl.java:83)
at org.jasig.portal.portlet.container.FilterManagerImpl.processFilter(FilterManagerImpl.java:102)
at org.apache.pluto.container.driver.PortletServlet.dispatch(PortletServlet.java:350)
at org.apache.pluto.container.driver.PortletServlet.doPost(PortletServlet.java:267)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:648)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:720)
at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:466)
at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:391)
at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:318)
at org.apache.pluto.driver.container.DefaultPortletInvokerService.invoke(DefaultPortletInvokerService.java:229)
at org.apache.pluto.driver.container.DefaultPortletInvokerService.serveResource(DefaultPortletInvokerService.java:149)
at sun.reflect.GeneratedMethodAccessor898.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
at org.jasig.portal.portlet.dao.jpa.ThreadContextClassLoaderAspect.doThreadContextClassLoaderUpdate(ThreadContextClassLoaderAspect.java:68)
at sun.reflect.GeneratedMethodAccessor162.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy209.serveResource(Unknown Source)
at org.apache.pluto.container.impl.PortletContainerImpl.doServeResource(PortletContainerImpl.java:203)
at org.jasig.portal.portlet.rendering.PortletRendererImpl.doServeResource(PortletRendererImpl.java:553)
at org.jasig.portal.portlet.rendering.worker.PortletResourceExecutionWorker.callInternal(PortletResourceExecutionWorker.java:53)
at org.jasig.portal.portlet.rendering.worker.PortletResourceExecutionWorker.callInternal(PortletResourceExecutionWorker.java:31)
at org.jasig.portal.portlet.rendering.worker.PortletExecutionWorker$1.call(PortletExecutionWorker.java:135)
at org.jasig.portal.portlet.rendering.worker.PortletExecutionWorker$ExecutionLifecycleCallable.call(PortletExecutionWorker.java:175)
at org.jasig.portal.portlet.rendering.worker.PortletExecutionCallable.call(PortletExecutionCallable.java:118)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)