IdP Broken resource pool - can anyone help

Wed Sep 19 10:03:22 EDT 2012

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.Ab
stractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration
for PrincipalConnector plugin with ID: shibTransient

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

11:37:13.273 - INFO
[edu.internet2.middleware.shibboleth.common.config.attribute.resolver.Ab
stractResolutionPlugInBeanDefinitionParser: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(BasicResou
rcePool.java:866) [c3p0-0.9.1.2.jar:0.9.1.2]

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

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

                at
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadP
oolAsynchronousRunner.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(BasicResou
rcePool.java:866) [c3p0-0.9.1.2.jar:0.9.1.2]

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

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

                at
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadP
oolAsynchronousRunner.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(BasicResou
rcePool.java:866) [c3p0-0.9.1.2.jar:0.9.1.2]

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

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

                at
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadP
oolAsynchronousRunner.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.checkoutPooledConnecti
on(C3P0PooledConnectionPool.java:531) ~[c3p0-0.9.1.2.jar:0.9.1.2]

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

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

                at
edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.S
hibbolethAttributeResolver.validateDataConnector(ShibbolethAttributeReso
lver.java:174) [shibboleth-common-1.3.7.jar:na]

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

                at
edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.S
hibbolethAttributeResolver.onNewContextCreated(ShibbolethAttributeResolv
er.java:536) [shibboleth-common-1.3.7.jar:na]

                at
edu.internet2.middleware.shibboleth.common.config.BaseService.loadContex
t(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.AbstractAutowireCapableBeanFac
tory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1414
) [spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

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

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

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

                at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFac
tory$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.AbstractAutowireCapableBeanFac
tory.createBean(AbstractAutowireCapableBeanFactory.java:380)
[spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

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

                at
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.g
etSingleton(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(Ab
stractBeanFactory.java:185) [spring-beans-2.5.6.SEC03.jar:2.5.6.SEC03]

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

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

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

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

                at
org.springframework.web.context.ContextLoader.createWebApplicationContex
t(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.j
ava:4791) [catalina.jar:7.0.30]

                at
org.apache.catalina.core.StandardContext.startInternal(StandardContext.j
ava: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.ja
va: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.j
ava: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(BasicResour
cePool.java:1315) ~[c3p0-0.9.1.2.jar:0.9.1.2]

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

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

                at
com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnecti
on(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 <a href="http://www.norfolk.gov.uk/emaildisclaimer">http://www.norfolk.gov.uk/emaildisclaimer</a>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://shibboleth.net/pipermail/users/attachments/20120919/5a27c0fe/attachment-0001.html 