[Shib-Users] weird resource pool error.....

113 views

Skip to first unread message

Steven_...@brown.edu

unread,

Nov 6, 2008, 3:38:03 PM11/6/08

to shibbole...@internet2.edu

recently, our IdP stopped issuing Attribute Assertions. A little log
snooping turned up the following entries...

we understand the "No metadata for relying party" msg... that's not the problem

the traceback, tho, includes "A RESOURCE POOL IS PERMANENTLY BROKEN! "....

and the next time someone hit the IdP that triggeed "Attempted to use
a closed or broken resource pool" (while trying to pull a persistent
ID value from the SQL DB)

can someone provide some info about these msgs... what might have caused this?

Thanks!

12:10:52.296 - WARN
[edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:255]
- No metadata for relying party
https://events.brown.edu/shibboleth-sp, treating party as anonymous
12:10:52.296 - ERROR
[edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:172]
- SAML 2 SSO profile is not configured for relying party
https://events.brown.edu/shibboleth-sp
12:10:52.297 - ERROR
[edu.internet2.middleware.shibboleth.common.profile.ProfileRequestDispatcherServlet:85]
- Error processing profile request
edu.internet2.middleware.shibboleth.common.profile.ProfileException:
SAML 2 SSO profile is not configured for relying party
https://events.brown.edu/shibboleth-sp
at
edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.performAuthentication(SSOProfileHandler.java:174)
[shibboleth-identityprovider-2.1.0.jar:na]
at
edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:144)
[shibboleth-identityprovider-2.1.0.jar:na]
at
edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:81)
[shibboleth-identityprovider-2.1.0.jar:na]
at
edu.internet2.middleware.shibboleth.common.profile.ProfileRequestDispatcherServlet.service(ProfileRequestDispatcherServlet.java:82)
[shibboleth-common-1.1.0.jar:na]
at
javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
[servlet-api.jar:na]
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
[catalina.jar:na]
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
[catalina.jar:na]
at
edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:77)
[shibboleth-identityprovider-2.1.0.jar:na]
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
[catalina.jar:na]
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
[catalina.jar:na]
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
[catalina.jar:na]
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:174)
[catalina.jar:na]
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
[catalina.jar:na]
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
[catalina.jar:na]
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
[catalina.jar:na]
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:174)
[catalina.jar:na] at
org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:874)
[tomcat-http.jar:na]
at
org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665)
[tomcat-http.jar:na]
at
org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528)
[tomcat-util.jar:5.1]
at
org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81)
[tomcat-util.jar:5.1]
at
org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:689)
[tomcat-util.jar:5.1] at java.lang.Thread.run(Thread.java:595)
[na:1.5.0_16]
18:58:41.358 - ERROR
[com.mchange.v2.resourcepool.BasicResourcePool:1853] - A RESOURCE
POOL IS PERMANENTLY BROKEN!
[com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@32d16dc8]18:58:41.359
- ERROR [com.mchange.v2.resourcepool.BasicResourcePool:866] -
com.mchange.v2.resourcepool.BasicResourcePool@43f854bd --
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]
18:58:41.360 - ERROR
[com.mchange.v2.resourcepool.BasicResourcePool:1853] - A RESOURCE
POOL IS PERMANENTLY BROKEN!
[com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@537e7f88]
18:58:41.360 - ERROR
[com.mchange.v2.resourcepool.BasicResourcePool:866] -
com.mchange.v2.resourcepool.BasicResourcePool@43f854bd --
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]

15:16:37.932 - ERROR
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.StoredIDDataConnector:183]
- Database error retrieving persistent identifier
java.sql.SQLException: An SQLException was provoked by the following
failure: com.mchange.v2.resourcepool.ResourcePoolException: Attempted
to use a closed or broken resource pool
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]

Scott Cantor

unread,

Nov 6, 2008, 6:15:27 PM11/6/08

to shibbole...@internet2.edu

> can someone provide some info about these msgs... what might have caused
> this?

The connection pooling code has settings controlling the number of retries
and what happens to the pool when they all fail. The default is to mark the
pool permanently dead, and that's the source of the message.

The default pool settings seem to be highly questionable (something like 36
retries with 5 seconds in between) and probably should be adjusted.

The ideal behavior is also, IMHO, to retry failure up to a point, then mark
it dead for some number of minutes, and then revive it. I don't know if
that's possible. This sort of thing is why I've tended to write my own pools
in the past.