Database connection pooling

[Wessel, Keith]

Hi, all,

We use the database-backed storage service, and this morning we had a rather strange incident on one of our IDP nodes. Calls to the status URL on the IDP were still returning fine, but redirects from SPs for users to log in were hanging until mod_jk timed out. The cause seems to be related to a connection pooling issue for the container database resource. We saw the below error repeatedly in our idp-process.log until we restarted Tomcat. The only performance parameter we have in our resource definition is the maxwait of 10,000 ms. Does anyone have any suggestions on what, if any, further parameters might help Tomcat recover from situations like this?

I'm still investigating the cause of the glitch in the first place. I suspect it's network-related, but I'm not yet sure.

Here's what we saw in the log. Any help appreciated.

07:29:02.229 - ERROR [org.hibernate.util.JDBCExceptionReporter:78] [session=] - Cannot get a connection, pool error Timeout waiting for idle object
07:29:02.231 - ERROR [net.clareitysecurity.shibboleth.db.SessionObjectDAOImpl:231] [session=] - Exception deleting idp session record [20640132]
org.hibernate.exception.GenericJDBCException: Cannot open connection
	at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103) ~[hibernate3.jar:3.2.5.ga]
	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91) ~[hibernate3.jar:3.2.5.ga]
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43) ~[hibernate3.jar:3.2.5.ga]
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29) ~[hibernate3.jar:3.2.5.ga]
	at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:426) ~[hibernate3.jar:3.2.5.ga]
	at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144) ~[hibernate3.jar:3.2.5.ga]
	at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:119) ~[hibernate3.jar:3.2.5.ga]
	at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:57) ~[hibernate3.jar:3.2.5.ga]
	at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1326) ~[hibernate3.jar:3.2.5.ga]
	at net.clareitysecurity.shibboleth.db.SessionObjectDAOImpl.openSession(SessionObjectDAOImpl.java:343) [db-storage-service-1.1.3.jar:na]
	at net.clareitysecurity.shibboleth.db.SessionObjectDAOImpl.delete(SessionObjectDAOImpl.java:223) [db-storage-service-1.1.3.jar:na]
	at net.clareitysecurity.shibboleth.db.SessionObjectDAOImpl.deleteBySessionId(SessionObjectDAOImpl.java:322) [db-storage-service-1.1.3.jar:na]
	at net.clareitysecurity.shibboleth.db.SessionObjectDAOImpl.removeSession(SessionObjectDAOImpl.java:209) [db-storage-service-1.1.3.jar:na]
	at net.clareitysecurity.shibboleth.storage.DbStorageService.remove(DbStorageService.java:423) [db-storage-service-1.1.3.jar:na]
	at net.clareitysecurity.shibboleth.storage.DbStorageService$PartitionEntryIterator.remove(DbStorageService.java:699) [db-storage-service-1.1.3.jar:na]
	at org.opensaml.util.storage.ExpiringObjectStorageServiceSweeper.run(ExpiringObjectStorageServiceSweeper.java:107) [openws-1.5.0.jar:na]
	at java.util.TimerThread.mainLoop(Timer.java:555) [na:1.7.0_60]
	at java.util.TimerThread.run(Timer.java:505) [na:1.7.0_60]
Caused by: org.apache.tomcat.dbcp.dbcp.SQLNestedException: Cannot get a connection, pool error Timeout waiting for idle object
	at org.apache.tomcat.dbcp.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:114) ~[tomcat-dbcp.jar:6.0.41]
	at org.apache.tomcat.dbcp.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044) ~[tomcat-dbcp.jar:6.0.41]
	at org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:69) ~[hibernate3.jar:3.2.5.ga]
	at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:423) ~[hibernate3.jar:3.2.5.ga]
	... 13 common frames omitted
Caused by: java.util.NoSuchElementException: Timeout waiting for idle object
	at org.apache.tomcat.dbcp.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1171) ~[tomcat-dbcp.jar:6.0.41]
	at org.apache.tomcat.dbcp.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:106) ~[tomcat-dbcp.jar:6.0.41]
	... 16 common frames omitted

Thanks,
Keith