"DB connection pool is depleted" errors and alfresco did not respond anymore

[koichinakata]

Hi experts,

My alfresco CE is 201706GA environment on amazon linux, m4.2xlarge, postgresql, solr4.

The instance is set both db.pool.max (alfresco-global.properties) and max_connections(postgresql.conf) as 300.

Today we have outages where the alfresco process is running but the application does not respond anymore. Only a restart of alfresco solves this issue. No outstanding CPU/RAM usage.

I found the error repeatedly in catalina.out.

2017-09-20 18:31:43,751 ERROR [util.transaction.TransactionSupportUtil] [defaultAsyncAction47] After completion (unknown) TransactionalCache exception
org.alfresco.util.transaction.ConnectionPoolException: 082029222 The DB connection pool is depleted.
at org.alfresco.util.transaction.SpringAwareUserTransaction.begin(SpringAwareUserTransaction.java:421)
at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:453)
at org.alfresco.repo.tenant.AbstractTenantRoutingContentStore.getAllStores(AbstractTenantRoutingContentStore.java:135)
at org.alfresco.repo.content.AbstractRoutingContentStore.isWriteSupported(AbstractRoutingContentStore.java:234)
at sun.reflect.GeneratedMethodAccessor1558.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.alfresco.repo.management.subsystems.SubsystemProxyFactory$1.invoke(SubsystemProxyFactory.java:79)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.alfresco.repo.management.subsystems.CryptodocSubsystemProxyFactory$1.invoke(CryptodocSubsystemProxyFactory.java:60)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy20.isWriteSupported(Unknown Source)
at org.alfresco.repo.content.cleanup.EagerContentStoreCleaner.deleteFromStores(EagerContentStoreCleaner.java:277)
at org.alfresco.repo.content.cleanup.EagerContentStoreCleaner.afterRollback(EagerContentStoreCleaner.java:254)
at org.alfresco.util.transaction.TransactionSupportUtil$TransactionSynchronizationImpl.afterCompletion(TransactionSupportUtil.java:601)

...

2017-09-20 18:31:43,884 ERROR [util.transaction.SpringAwareUserTransaction] [defaultAsyncAction47] Application exception overridden by rollback exception
java.lang.Exception
at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:547)
at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:533)
at org.alfresco.repo.tenant.AbstractTenantRoutingContentStore.getAllStores(AbstractTenantRoutingContentStore.java:135)
at org.alfresco.repo.content.AbstractRoutingContentStore.isWriteSupported(AbstractRoutingContentStore.java:234)
at sun.reflect.GeneratedMethodAccessor1558.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.alfresco.repo.management.subsystems.SubsystemProxyFactory$1.invoke(SubsystemProxyFactory.java:79)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.alfresco.repo.management.subsystems.CryptodocSubsystemProxyFactory$1.invoke(CryptodocSubsystemProxyFactory.java:60)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy20.isWriteSupported(Unknown Source)
at org.alfresco.repo.content.cleanup.EagerContentStoreCleaner.deleteFromStores(EagerContentStoreCleaner.java:277)
at org.alfresco.repo.content.cleanup.EagerContentStoreCleaner.afterRollback(EagerContentStoreCleaner.java:254)
at org.alfresco.util.transaction.TransactionSupportUtil$TransactionSynchronizationImpl.afterCompletion(TransactionSupportUtil.java:601)

...

2017-09-20 18:45:04,918 ERROR [transaction.support.TransactionSynchronizationUtils] [http-apr-8080-exec-2805] TransactionSynchronization.beforeCompletion threw exception
java.lang.IllegalStateException: No value for key [org.apache.ibatis.session.defaults.DefaultSqlSessionFactory@1c96a2a7] bound to thread [http-apr-8080-exec-2805]
at org.springframework.transaction.support.TransactionSynchronizationManager.unbindResource(TransactionSynchronizationManager.java:209)
at org.mybatis.spring.SqlSessionUtils$SqlSessionSynchronization.beforeCompletion(SqlSessionUtils.java:314)
at org.springframework.transaction.support.TransactionSynchronizationUtils.triggerBeforeCompletion(TransactionSynchronizationUtils.java:106)

[jpotts]

Your DB connection pool is depleted as shown in the logs. Once the pool is depleted, a restart is the only way to fix the problem. Maybe your question is "What caused my DB connection pool to be depleted?" but we aren't going to be able to answer that without additional context. Have you seen a spike in usage? Were you doing a large import? What has the DB connection trend been over time leading up to this point? What changed?

[lmaorence]

This may be caused by too many concurrent connections to your database that ended up using and depleting the maximum connection pool. I suggest you try increasing your connection pools both alfresco and in database given that your memory can handle the load and see if this issue persists.