Activit DB Connection pool leak on WL

[schitale]

I didnt get any answer on activiti engine forum for this:

I see this multiple times in the WL log:

ACTIVITI_DB_POOL is the conn pool we use to connect to activit engine.

<Sep 24, 2013 7:39:10 PM EDT> <Notice> <Stdout> <BEA-000000> <Returning ALBPM JDBC Connection ….>
<Sep 24, 2013 7:39:23 PM EDT> <Warning> <JDBC> <BEA-001153> <Forcibly releasing inactive connection "weblogic.jdbc.wrapper.PoolConnection_oracle_jdbc_driver_T4CConnection@17a3db" back into the connection pool "ACTIVITI_DB_POOL", currently reserved by: java.lang.Exception
        at weblogic.jdbc.common.internal.ConnectionEnv.setup(ConnectionEnv.java:308)
        at weblogic.common.resourcepool.ResourcePoolImpl.reserveResource(ResourcePoolImpl.java:314)
        at weblogic.common.resourcepool.ResourcePoolImpl.reserveResource(ResourcePoolImpl.java:292)
        at weblogic.jdbc.common.internal.ConnectionPool.reserve(ConnectionPool.java:425)


I also keep getting this error all the time. What exactly is going wrong, I'm not sure? (Are the two stack traces related some how?)

I'm using WL datasource with JTA transaction.

WARNING: Exception or error caught in resource
org.apache.ibatis.exceptions.PersistenceException:
### Error updating database. Cause: java.sql.SQLException: Connection has already been closed.
### SQL: insert into ACT_HI_VARINST (ID_, PROC_INST_ID_, EXECUTION_ID_, TASK_ID_, NAME_, REV_, VAR_TYPE_, BYTEARRAY_ID_, DOUBLE_, LONG_ , TEXT_, TEXT2_) values ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ? )
### Cause: java.sql.SQLException: Connection has already been closed.
at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:23)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:150)
at org.apache.ibatis.session.defaults.DefaultSqlSession.insert(DefaultSqlSession.java:137)
at org.activiti.engine.impl.db.DbSqlSession.flushInserts(DbSqlSession.java:538)
at org.activiti.engine.impl.db.DbSqlSession.flush(DbSqlSession.java:441)
at org.activiti.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:169)
at org.activiti.engine.impl.interceptor.CommandContext.close(CommandContext.java:116)
at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:70)
at org.activiti.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:42)
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130)
at org.activiti.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:40)
at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:31)
at org.activiti.engine.impl.TaskServiceImpl.complete(TaskServiceImpl.java:167)
at org.activiti.rest.api.runtime.task.TaskResource.completeTask(TaskResource.java:131)
at org.activiti.rest.api.runtime.task.TaskResource.executeTaskAction(TaskResource.java:80)
…
Caused by: java.sql.SQLException: Connection has already been closed.
at weblogic.jdbc.wrapper.PoolConnection.checkConnection(PoolConnection.java:55)
at weblogic.jdbc.wrapper.Connection.preInvocationHandler(Connection.java:92)
at weblogic.jdbc.wrapper.Connection.prepareStatement(Connection.java:482)
at sun.reflect.GeneratedMethodAccessor73.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy$TransactionAwareInvocationHandler.invoke(TransactionAwareDataSourceProxy.java:239)
at com.sun.proxy.$Proxy73.prepareStatement(Unknown Source)
at org.apache.ibatis.executor.statement.PreparedStatementHandler.instantiateStatement(PreparedStatementHandler.java:72)
at org.apache.ibatis.executor.statement.BaseStatementHandler.prepare(BaseStatementHandler.java:82)
at org.apache.ibatis.executor.statement.RoutingStatementHandler.prepare(RoutingStatementHandler.java:54)
at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:70)
at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:44)
at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:100)
at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:75)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:1

[schitale]

* I see this multiple times in the WL log:

<code>
<Sep 24, 2013 7:39:10 PM EDT> <Notice> <Stdout> <BEA-000000> <Returning ALBPM JDBC Connection ….>
<Sep 24, 2013 7:39:23 PM EDT> <Warning> <JDBC> <BEA-001153> <Forcibly releasing inactive connection "weblogic.jdbc.wrapper.PoolConnection_oracle_jdbc_driver_T4CConnection@17a3db" back into the connection pool "Activiti_S300_ACTIVITI_DB_POOL_V1", currently reserved by: java.lang.Exception
        at weblogic.jdbc.common.internal.ConnectionEnv.setup(ConnectionEnv.java:308)
        at weblogic.common.resourcepool.ResourcePoolImpl.reserveResource(ResourcePoolImpl.java:314)
        at weblogic.common.resourcepool.ResourcePoolImpl.reserveResource(ResourcePoolImpl.java:292)
        at weblogic.jdbc.common.internal.ConnectionPool.reserve(ConnectionPool.java:425)

</code>

[schitale]

* Sep 24, 2013 7:39:23 PM EDT Warning JDBC BEA-001153Forcibly releasing inactive connection "weblogic.jdbc.wrapper.PoolConnection_oracle_jdbc_driver_T4CConnection@17a3db" back into the connection pool "ACTIVITI_DB_POOL", currently reserved by: java.lang.Exception
        at weblogic.jdbc.common.internal.ConnectionEnv.setup(ConnectionEnv.java:308)
        at weblogic.common.resourcepool.ResourcePoolImpl.reserveResource(ResourcePoolImpl.java:314)
        at weblogic.common.resourcepool.ResourcePoolImpl.reserveResource(ResourcePoolImpl.java:292)
        at weblogic.jdbc.common.internal.ConnectionPool.reserve(ConnectionPool.java:425)

[frederikherema1]

What process-engine configuration are you using? Seems that the activity interceptors are closing the connections manually, instead of having the transaction-provider handle this. Depending on your ProcessEngineCOnfiguration subclass, this shouldn't happen…

[melentye]

Hello schitale,

what are your logging/profiling settings that allow you to see second exception? What is the value of "Inactive Connection Timeout" setting in "advanced" part of ACTIVITI_DB_POOL data source configuration in WL domain console?

We have noticed connection leak on Weblogic 12c with Activiti 5.12.1 as well but its not logged or reported anywhere unless we switch on Data Source Profile Log - we just see that over time we run out of connections rather quickly on highly loaded system

thanks,
Andrey

[melentye]

@frederikheremans, just in case: we're facing similar (or same) issue and we use JtaProcessEngineConfiguration and in activiti.cfg.xml we're pointing to weblogic TransactionManager JNDI name

[schitale]

This is my config xml.

<jee:jndi-lookup id="activitiDataSource" jndi-name="ACTIVITI_DB_POOL_V1"/>

<bean id="transactionManager"
  class="org.springframework.transaction.jta.JtaTransactionManager">
  <!– property name="dataSource" ref="activitiDataSource" / –>
</bean>

<bean id="bpmConnectionParams" class="com.xxx.activiti.identity.BpmConnectionParams" />

   <bean id="springJobExecutor" class="org.activiti.spring.components.jobexecutor.SpringJobExecutor">
  <property name="taskExecutor">
   <bean class="org.springframework.scheduling.commonj.WorkManagerTaskExecutor">
    <property name="workManagerName" value="wm/ActivitiWM" />
    <property name="resourceRef" value="true" />
   </bean>
  </property>
</bean>

<bean id="processEngineConfiguration" class="org.activiti.spring.SpringProcessEngineConfiguration">
  <property name="dataSource" ref="activitiDataSource" />
  <property name="transactionManager" ref="transactionManager" />
  <property name="databaseSchemaUpdate" value="true" />
  <property name="mailServerHost" value="localhost" />
  <property name="mailServerPort" value="5025" />

  <property name="jobExecutor" ref="springJobExecutor" />
  <property name="jobExecutorActivate" value="true" />

  <!– NONE("none"),
  ACTIVITY("activity"),
  AUDIT("audit"),
  FULL("full"); –>
  <property name="history" value="none" />

  <property name="customSessionFactories">
   <list>
    <bean class="com.xxx.activiti.identity.BpmGroupManagerFactory">
     <constructor-arg ref="bpmConnectionParams" />
    </bean>
    <bean class="com.xxx.activiti.identity.BpmUserManagerFactory">
     <constructor-arg ref="bpmConnectionParams" />
    </bean>
   </list>
  </property>
</bean>

<bean id="processEngine" class="org.activiti.spring.ProcessEngineFactoryBean">
  <property name="processEngineConfiguration" ref="processEngineConfiguration" />
</bean>

[schitale]

One more follow up.

We have fairly long running WS calls . ( > 60 sec and we are trying to fix it.)

I've set "Inactive Connection Timeout" to 0 in my dev env and for now it is not showing any problem obviously.

Earlier that value was 60.

I've tested probably 30/40 request after that and I've not seen any thread hogging up connections.

I'm not sure, but my understanding is (and I may be wrong) that since my WS calls are more that 60s the transaction started by BPM is taken back resulting in:

* Sep 24, 2013 7:39:23 PM EDT Warning JDBC BEA-001153Forcibly releasing inactive connection "weblogic.jdbc.wrapper.PoolConnection_oracle_jdbc_driver_T4CConnection@17a3db" back into the connection pool "ACTIVITI_DB_POOL", currently reserved by: java.lang.Exception

When the WS call returns and process instance completes, the connection is closed for the activiti thread.

I may be mistaken, please correct me.

[frederikherema1]

Yes, that makes sense… If you expect long-running operations, make sure your transaction-timeout is high enough. Offcourse, long-running transactions is not always a good idea. Another approach whould be to use camel (for example) for the long-running work,without keeping a transaction in activiti open. Or if not using camel, use a receive-task and trigger the long-running work in another system/app. once that app completes the operation, "signal" activiti, providing the result of the operation. Than, activiti can continue the process

[arunpmohan]

I still see connection leak on activiti 5.13 on weblogic 10.3.5.
Is there any fix in activiti 5.14 for connection leaks?