JIRA Timesheet Plugin caused connection pool timeout

The atlassian support informed me that our sporadic JIRA freezes are caused by your plugin. Therefor please see attached files and comments, perhaps you´ve an idea what´s going wrong...

In case of any questions please let me know!

Thanks & regards, Hans-Hermann

Thanks for the extra log files and Task Manager screenshots. So looking at the GC logs, memory is not an issue. The most it ever uses is 2gb and then it goes down to an average of 1gb. Can you please lower the memory to a maximum of 2048mb? Providing more memory to a JVM can actually make it operate worse. What can happen with GC is the instance gets stuck garbage collecting and this will chew up your CPU, however we can see this isn't a problem.

Reviewing the logs, it looks like this is what has caused the failure:

ERROR wroetman 536x46656x1 1rbpg55 172.20.108.184,172.20.25.71 /rest/timesheet-gadget/1.0/timesheet.json [NoModule] There was an error getting a DBCP datasource.
java.lang.RuntimeException: Unable to obtain a connection from the underlying connection pool
    at org.ofbiz.core.entity.jdbc.interceptors.connection.ConnectionTracker.trackConnection(ConnectionTracker.java:59)
    at org.ofbiz.core.entity.transaction.DBCPConnectionFactory.trackConnection(DBCPConnectionFactory.java:242)
    at org.ofbiz.core.entity.transaction.DBCPConnectionFactory.getConnection(DBCPConnectionFactory.java:73)
    at org.ofbiz.core.entity.ConnectionFactory.tryGenericConnectionSources(ConnectionFactory.java:69)
    at org.ofbiz.core.entity.transaction.JNDIFactory.getConnection(JNDIFactory.java:146)
    at org.ofbiz.core.entity.TransactionFactory.getConnection(TransactionFactory.java:101)
    at org.ofbiz.core.entity.ConnectionFactory.getConnection(ConnectionFactory.java:59)
    at org.ofbiz.core.entity.jdbc.SQLProcessor.getConnection(SQLProcessor.java:367)
    at org.ofbiz.core.entity.jdbc.SQLProcessor.prepareStatement(SQLProcessor.java:515)
    at org.ofbiz.core.entity.GenericDAO.selectListIteratorByCondition(GenericDAO.java:1040)
    at org.ofbiz.core.entity.GenericHelperDAO.findListIteratorByCondition(GenericHelperDAO.java:175)
    at org.ofbiz.core.entity.GenericDelegator.findListIteratorByCondition(GenericDelegator.java:999)
    at org.ofbiz.core.entity.GenericDelegator.findListIteratorByCondition(GenericDelegator.java:972)
    at jira.plugin.report.timesheet.TimeBaseService.getTimeSpents(TimeBaseService.java:203)
    at com.fdu.jira.plugin.gadget.timesheet.TimeSheetResource.getVelocityParams(TimeSheetResource.java:219)
    at com.fdu.jira.plugin.gadget.timesheet.TimeSheetResource.getVelocityParams(TimeSheetResource.java:160)
    at com.fdu.jira.plugin.gadget.timesheet.TimeSheetResource.getTimesheet(TimeSheetResource.java:136)
    ...
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot get a connection, pool error Timeout waiting for idle object
    at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:114)
    at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)
    ...
Caused by: java.util.NoSuchElementException: Timeout waiting for idle object
    at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1134)
    at org.apache.commons.dbcp.AbandonedObjectPool.borrowObject(AbandonedObjectPool.java:79)
    ...

So JIRA was attempting to talk to the DB, it couldn't as the connection pool timed out. The database connection pool (DBCP) is the way that JIRA talks to your DB, Oracle. Different threads consume a connection when they're used and then the connection is returned back into the pool for another thread. If a connection isn't available, that thread can't talk to the DB - eventually JIRA will run out out connections come grinding to a halt and was no longer able to function.

Scanning back into the logs to see what caused this, we can see the following:

org.apache.commons.dbcp.AbandonedTrace$AbandonedObjectException: DBCP object created 2013-08-19 08:04:03 by the following code was never closed:
    at org.apache.commons.dbcp.AbandonedTrace.setStackTrace(AbandonedTrace.java:139)
    at org.apache.commons.dbcp.AbandonedObjectPool.borrowObject(AbandonedObjectPool.java:81)
    at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:106)
    at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)
    at org.ofbiz.core.entity.transaction.DBCPConnectionFactory$1.call(DBCPConnectionFactory.java:246)
    at org.ofbiz.core.entity.transaction.DBCPConnectionFactory$1.call(DBCPConnectionFactory.java:243)
    at org.ofbiz.core.entity.jdbc.interceptors.connection.ConnectionTracker.trackConnection(ConnectionTracker.java:53)
    at org.ofbiz.core.entity.transaction.DBCPConnectionFactory.trackConnection(DBCPConnectionFactory.java:242)
    at org.ofbiz.core.entity.transaction.DBCPConnectionFactory.getConnection(DBCPConnectionFactory.java:73)
    at org.ofbiz.core.entity.ConnectionFactory.tryGenericConnectionSources(ConnectionFactory.java:69)
    at org.ofbiz.core.entity.transaction.JNDIFactory.getConnection(JNDIFactory.java:146)
    at org.ofbiz.core.entity.TransactionFactory.getConnection(TransactionFactory.java:101)
    at org.ofbiz.core.entity.ConnectionFactory.getConnection(ConnectionFactory.java:59)
    at org.ofbiz.core.entity.jdbc.SQLProcessor.getConnection(SQLProcessor.java:367)
    at org.ofbiz.core.entity.jdbc.SQLProcessor.prepareStatement(SQLProcessor.java:515)
    at org.ofbiz.core.entity.GenericDAO.selectListIteratorByCondition(GenericDAO.java:1040)
    at org.ofbiz.core.entity.GenericHelperDAO.findListIteratorByCondition(GenericHelperDAO.java:175)
    at org.ofbiz.core.entity.GenericDelegator.findListIteratorByCondition(GenericDelegator.java:999)
    at org.ofbiz.core.entity.GenericDelegator.findListIteratorByCondition(GenericDelegator.java:972)
    at jira.plugin.report.timesheet.TimeBaseService.getTimeSpents(TimeBaseService.java:203)
    at com.fdu.jira.plugin.gadget.timesheet.TimeSheetResource.getVelocityParams(TimeSheetResource.java:219)
    at com.fdu.jira.plugin.gadget.timesheet.TimeSheetResource.getVelocityParams(TimeSheetResource.java:160)
    at com.fdu.jira.plugin.gadget.timesheet.TimeSheetResource.getTimesheet(TimeSheetResource.java:136)

It looks like the JIRA Timesheet Reports and Gadgets Plugin is causing this, as the instance is reporting that those objects weren't closed. This is a likely cause of the DBCP issues.

Comments (4)