More fun with IDP V2 and the database backed storage service

Wed Jun 17 16:28:06 EDT 2015

Hi Keith,

For Oracle we set connectionProperties="oracle.net.CONNECT_TIMEOUT=5000;oracle.jdbc.ReadTimeout=5000", which seems to do the trick.

Thanks,
Ryan

On 6/17/15, 15:07 , "users on behalf of Wessel, Keith" <users-bounces at shibboleth.net on behalf of kwessel at illinois.edu> wrote:

>All,
>
>Wondering if there's some type of JNDI parameter or low-level driver parameter that effects how long a Tomcat DB connection pool will wait for a connection. Something happened this morning that, as far as I can tell, shouldn't.
>
>We had a SAN failure that took down our Oracle database. I'd expect that, finding no connections in the pool with maxWait=1000, Tomcat would have returned no connections available and the DB-backed storage service would have gone on its merry way. Instead, it caused Tomcat to hang for longer than the mod_jk connection timeout in Apache which resulted in gateway timeout errors to users after clicking the login button.
>
>Because the Oracle server was totally down, we had connections timing out instead of just refused. I think that confused things. My theory is that the low-level Oracle driver was causing the delay and, for whatever reason, the connection pool logic which should have caused things to proceed without a database didn't have a chance to fire. Is there a parameter to control how long a network connection will wait before returning connection timed out? Here's the log snippet:
>
>08:11:58.201 - ERROR [net.clareitysecurity.shibboleth.db.SessionObjectDAOImpl:296] [session=] -
>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.getCsIdpSession(SessionObjectDAOImpl.java:278) [db-storage-service-1.1.3.jar:na]
>at net.clareitysecurity.shibboleth.db.SessionObjectDAOImpl.getSession(SessionObjectDAOImpl.java:162) [db-storage-service-1.1.3.jar:na]
>at net.clareitysecurity.shibboleth.storage.DbStorageService.getPersistent(DbStorageService.java:245) [db-storage-service-1.1.3.jar:na]
>at net.clareitysecurity.shibboleth.storage.DbStorageService.get(DbStorageService.java:297) [db-storage-service-1.1.3.jar:na]
>at edu.internet2.middleware.shibboleth.idp.session.impl.SessionManagerImpl.getSession(SessionManagerImpl.java:143) [shibboleth-identityprovider-2.4.2.jar:na]
>at edu.internet2.middleware.shibboleth.idp.session.impl.SessionManagerImpl.getSession(SessionManagerImpl.java:33) [shibboleth-identityprovider-2.4.2.jar:na]
>at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.getUserSession(IdPSessionFilter.java:172) [shibboleth-identityprovider-2.4.2.jar:na]
>at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:79) [shibboleth-identityprovider-2.4.2.jar:na]
>at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.41]
>at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.41]
>at edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:52) [shibboleth-common-1.4.2.jar:na]
>at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.41]
>at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.41]
>at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina.jar:6.0.41]
>at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina.jar:6.0.41]
>at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina.jar:6.0.41]
>at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina.jar:6.0.41]
>at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina.jar:6.0.41]
>at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) [catalina.jar:6.0.41]
>at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190) [tomcat-coyote.jar:6.0.41]
>at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:311) [tomcat-coyote.jar:6.0.41]
>at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:776) [tomcat-coyote.jar:6.0.41]
>at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:705) [tomcat-coyote.jar:6.0.41]
>at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:898) [tomcat-coyote.jar:6.0.41]
>at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690) [tomcat-coyote.jar:6.0.41]
>at java.lang.Thread.run(Thread.java:745) [na:1.7.0_60]
>Caused by: org.apache.tomcat.dbcp.dbcp.SQLNestedException: Cannot create PoolableConnectionFactory (The Network Adapter could not establish the connection)
>at org.apache.tomcat.dbcp.dbcp.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:1549) ~[tomcat-dbcp.jar:6.0.41]
>at org.apache.tomcat.dbcp.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:1388) ~[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]
>... 31 common frames omitted
>Caused by: java.sql.SQLException: The Network Adapter could not establish the connection
>at oracle.jdbc.driver.SQLStateMapping.newSQLException(SQLStateMapping.java:70) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.jdbc.driver.DatabaseError.newSQLException(DatabaseError.java:133) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:199) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:480) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:413) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:508) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:203) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:33) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:510) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at org.apache.tomcat.dbcp.dbcp.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:38) ~[tomcat-dbcp.jar:6.0.41]
>at org.apache.tomcat.dbcp.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:582) ~[tomcat-dbcp.jar:6.0.41]
>at org.apache.tomcat.dbcp.dbcp.BasicDataSource.validateConnectionFactory(BasicDataSource.java:1556) ~[tomcat-dbcp.jar:6.0.41]
>at org.apache.tomcat.dbcp.dbcp.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:1545) ~[tomcat-dbcp.jar:6.0.41]
>... 35 common frames omitted
>Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection
>at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:328) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:421) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:630) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.net.ns.NSProtocol.connect(NSProtocol.java:206) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:966) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:292) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>... 43 common frames omitted
>Caused by: java.net.ConnectException: Connection timed out
>at java.net.PlainSocketImpl.socketConnect(Native Method) ~[na:1.7.0_60]
>at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) ~[na:1.7.0_60]
>at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) ~[na:1.7.0_60]
>at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) ~[na:1.7.0_60]
>at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[na:1.7.0_60]
>at java.net.Socket.connect(Socket.java:579) ~[na:1.7.0_60]
>at java.net.Socket.connect(Socket.java:528) ~[na:1.7.0_60]
>at java.net.Socket.<init>(Socket.java:425) ~[na:1.7.0_60]
>at java.net.Socket.<init>(Socket.java:208) ~[na:1.7.0_60]
>at oracle.net.nt.TcpNTAdapter.connect(TcpNTAdapter.java:127) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.net.nt.ConnOption.connect(ConnOption.java:126) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:306) ~[ojdbc6.jar:Oracle JDBC Driver version - "11.1.0.7.0-Production"]
>... 48 common frames omitted
>
>Thanks for any help,
>Keith
>
>-- 
>To unsubscribe from this list send an email to users-unsubscribe at shibboleth.net