IdP Broken resource pool - can anyone help

Wed Sep 19 10:37:09 EDT 2012

I should also say that I have had issues with JDBC to SQL Server with user/password in the URL and always ended up using
integratedSecurity=true;

ISTR that this manifests itself as a failure of the sort you mention.  But if you IdP was working beforehand it shouldn't be any of
these.

From: users-bounces at shibboleth.net [mailto:users-bounces at shibboleth.net] On Behalf Of Baird-Parker, David
Sent: 19 September 2012 15:03
To: users at shibboleth.net
Subject: IdP Broken resource pool - can anyone help

Hi,

up to last Thursday we had a working IdP or so we appeared to have anyway.  A school raised an issue and we found our metadata
hadn't updated for the UK Federation as it normally would - this is normally fixed by a restart of Tomcat.  I haven't been able to
get it back to a working state and need some advice on what to do.  With the breakdown, I took the opportunity to update most of the
services on our IdP as follows:

JDK:- 1.6.23 -> 1.7.07

Shib IdP 2.3.3 -> 2.3.8

Tomcat 7.0.8 -> 7.0.30

I have also downloaded the latest MS JDBC driver to connect to our MS SQL database on a separate virtual machine.  I can telnet to
the machine on the port specified from the IdP machine so all is well there.

Following advice online I have today tried the jtds driver and updated the URL's in our attribute-resolver file accordingly.  The
last time I started Tomcat (this morning) Tomcat started successfully but the idp-process file has the following content:

11:37:12.961 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:158] - Loading new configuration for service
shibboleth.AttributeResolver

11:37:13.023 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for PrincipalConnector plugin with ID: shibTransient

11:37:13.023 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for PrincipalConnector plugin with ID: saml1Unspec

11:37:13.023 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for PrincipalConnector plugin with ID: saml2Transient

11:37:13.039 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for DataConnector plugin with ID: static1

11:37:13.039 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for DataConnector plugin with ID: storedID

11:37:13.164 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for DataConnector plugin with ID: dbPersonInfo

11:37:13.195 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for DataConnector plugin with ID: dbRoles

11:37:13.242 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: eduPersonEntitlement

11:37:13.257 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: eduPersonPrincipalName

11:37:13.257 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: PrincipalName

11:37:13.257 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: eduPersonScopedAffiliation

11:37:13.257 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: eduPersonAffiliation

11:37:13.257 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: eduPersonTargetedID

11:37:13.257 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: title

11:37:13.257 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: sn

11:37:13.273 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: givenName

11:37:13.273 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: cn

11:37:13.273 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: DCSF

11:37:13.273 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: LEAcode

11:37:13.273 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: transientId

11:37:13.273 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing
configuration for AttributeDefinition plugin with ID: principal

11:40:08.961 - ERROR [com.mchange.v2.resourcepool.BasicResourcePool:1853] - A RESOURCE POOL IS PERMANENTLY BROKEN!
[com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask at 66212948]

11:40:08.961 - ERROR [com.mchange.v2.resourcepool.BasicResourcePool:1853] - A RESOURCE POOL IS PERMANENTLY BROKEN!
[com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask at 74ff6842]

11:40:08.961 - ERROR [com.mchange.v2.resourcepool.BasicResourcePool:1853] - A RESOURCE POOL IS PERMANENTLY BROKEN!
[com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask at 6a81e18e]

11:40:08.976 - ERROR [com.mchange.v2.resourcepool.BasicResourcePool:866] - com.mchange.v2.resourcepool.BasicResourcePool at 40e8ecbd --
Unexpectedly broken!!!

com.mchange.v2.resourcepool.ResourcePoolException: Unexpected Break Stack Trace!

                at com.mchange.v2.resourcepool.BasicResourcePool.unexpectedBreak(BasicResourcePool.java:866)
[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.resourcepool.BasicResourcePool.access$1100(BasicResourcePool.java:32) [c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1854)
[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
[c3p0-0.9.1.2.jar:0.9.1.2]

11:40:08.976 - ERROR [com.mchange.v2.resourcepool.BasicResourcePool:866] - com.mchange.v2.resourcepool.BasicResourcePool at 40e8ecbd --
Unexpectedly broken!!!

com.mchange.v2.resourcepool.ResourcePoolException: Unexpected Break Stack Trace!

                at com.mchange.v2.resourcepool.BasicResourcePool.unexpectedBreak(BasicResourcePool.java:866)
[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.resourcepool.BasicResourcePool.access$1100(BasicResourcePool.java:32) [c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1854)
[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
[c3p0-0.9.1.2.jar:0.9.1.2]

11:40:08.976 - ERROR [com.mchange.v2.resourcepool.BasicResourcePool:866] - com.mchange.v2.resourcepool.BasicResourcePool at 40e8ecbd --
Unexpectedly broken!!!

com.mchange.v2.resourcepool.ResourcePoolException: Unexpected Break Stack Trace!

                at com.mchange.v2.resourcepool.BasicResourcePool.unexpectedBreak(BasicResourcePool.java:866)
[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.resourcepool.BasicResourcePool.access$1100(BasicResourcePool.java:32) [c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1854)
[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
[c3p0-0.9.1.2.jar:0.9.1.2]

11:40:08.976 - ERROR [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.RDBMSDataConnector:243] -
RDBMS data connector [dbRoles] - Invalid connector configuration

java.sql.SQLException: An SQLException was provoked by the following failure: java.lang.InterruptedException

                at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:106) ~[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:65) ~[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:62) ~[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:531)
~[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)
~[c3p0-0.9.1.2.jar:0.9.1.2]

                at
edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.RDBMSDataConnector.validate(RDBMSDataConnector.
java:224) ~[shibboleth-common-1.3.7.jar:na]

                at
edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver.validateDataConnector(ShibbolethA
ttributeResolver.java:174) [shibboleth-common-1.3.7.jar:na]

                at
edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver.validate(ShibbolethAttributeResol
ver.java:146) [shibboleth-common-1.3.7.jar:na]

                at
edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver.onNewContextCreated(ShibbolethAtt
ributeResolver.java:536) [shibboleth-common-1.3.7.jar:na]

                at edu.internet2.middleware.shibboleth.common.config.BaseService.loadContext(BaseService.java:174)
[shibboleth-common-1.3.7.jar:na]

                at
edu.internet2.middleware.shibboleth.common.config.BaseReloadableService.initialize(BaseReloadableService.java:148)
[shibboleth-common-1.3.7.jar:na]

                at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_07]

                at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[na:1.7.0_07]

                at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.7.0_07]

                at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.7.0_07]

                at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFacto
ry.java:1414) [spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

                at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.ja
va:1375) [spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

                at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:
1335) [spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

                at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:47
3) [spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

                at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory$1.run(AbstractAutowireCapableBeanFactory.java:409)
[spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

                at java.security.AccessController.doPrivileged(Native Method) [na:1.7.0_07]

                at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:380)
[spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

                at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:264)
[spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

                at
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
[spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

                at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:261)
[spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

                at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:185)
[spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

                at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:164)
[spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

                at
org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:429)
[spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

                at
org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:728)
[spring-context-2.5.6.SEC03.jar:2.5.6.SEC03]

                at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:380)
[spring-context-2.5.6.SEC03.jar:2.5.6.SEC03]

                at org.springframework.web.context.ContextLoader.createWebApplicationContext(ContextLoader.java:255)
[spring-web-2.5.6.SEC03.jar:2.5.6.SEC03]

                at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:199)
[spring-web-2.5.6.SEC03.jar:2.5.6.SEC03]

                at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:45)
[spring-web-2.5.6.SEC03.jar:2.5.6.SEC03]

                at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4791) [catalina.jar:7.0.30]

                at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5285) [catalina.jar:7.0.30]

                at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150) [catalina.jar:7.0.30]

                at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:901) [catalina.jar:7.0.30]

                at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:877) [catalina.jar:7.0.30]

                at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:618) [catalina.jar:7.0.30]

                at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:650) [catalina.jar:7.0.30]

                at org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1582) [catalina.jar:7.0.30]

                at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) [na:1.7.0_07]

                at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source) [na:1.7.0_07]

                at java.util.concurrent.FutureTask.run(Unknown Source) [na:1.7.0_07]

                at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [na:1.7.0_07]

                at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [na:1.7.0_07]

                at java.lang.Thread.run(Unknown Source) [na:1.7.0_07]

Caused by: java.lang.InterruptedException: null

                at java.lang.Object.wait(Native Method) ~[na:1.7.0_07]

                at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1315)
~[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:557)
~[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:477)
~[c3p0-0.9.1.2.jar:0.9.1.2]

                at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:525)
~[c3p0-0.9.1.2.jar:0.9.1.2]

                ... 43 common frames omitted

11:40:08.976 - ERROR [edu.internet2.middleware.shibboleth.common.config.BaseService:188] - Configuration was not loaded for
shibboleth.AttributeResolver service, error creating components.  The root cause of this error was: java.lang.InterruptedException:
null

If anyone can help at all I'd really appreciate it.

Thanks,

David Baird-Parker

--

To see our email disclaimer click here http://www.norfolk.gov.uk/emaildisclaimer
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://shibboleth.net/pipermail/users/attachments/20120919/788da3c8/attachment-0001.html 