[Shib-Users] opensaml::BindingException caused by CKR_SESSION_HANDLE_INVALID?
Harald Strack
we are receiving occasional complaints from users which get a
opensaml::BindingException on a SP. On our IDP we could locate the
following corresponding messages:
Unable to resolve artifact(s) into a SAML response.
Rejecting replayed artifact (AAQAArHKpA2t81ko0IOfkKP1rRnYERRsF5LAqcwPhdTr+ILixAOfFXJeLng=).
caused by a:
sun.security.pkcs11.wrapper.PKCS11Exception: CKR_SESSION_HANDLE_INVALID
Details in the stack trace below.
20:35:03.113 - ERROR [edu.internet2.middleware.shibboleth.common.profile.ProfileRequestDispatcherServlet:88] - Error occured while processing request
java.security.ProviderException: Initialization failed
at sun.security.pkcs11.P11Signature.initialize(P11Signature.java:295) [sunpkcs11.jar:na]
at sun.security.pkcs11.P11Signature.ensureInitialized(P11Signature.java:219) [sunpkcs11.jar:na]
at sun.security.pkcs11.P11Signature.engineUpdate(P11Signature.java:406) [sunpkcs11.jar:na]
at java.security.Signature$Delegate.engineUpdate(Signature.java:1118) [na:1.6.0_18]
at java.security.Signature.update(Signature.java:684) [na:1.6.0_18]
at org.apache.xml.security.algorithms.implementations.SignatureBaseRSA.engineUpdate(Unknown Source) [xmlsec-1.4.3
.jar:na]
at org.apache.xml.security.algorithms.SignatureAlgorithm.update(Unknown Source) [xmlsec-1.4.3.jar:na]
at org.apache.xml.security.utils.SignerOutputStream.write(Unknown Source) [xmlsec-1.4.3.jar:na]
at org.apache.xml.security.utils.UnsyncBufferedOutputStream.flushBuffer(Unknown Source) [xmlsec-1.4.3.jar:na]
at org.apache.xml.security.utils.UnsyncBufferedOutputStream.flush(Unknown Source) [xmlsec-1.4.3.jar:na]
at org.apache.xml.security.utils.UnsyncBufferedOutputStream.close(Unknown Source) [xmlsec-1.4.3.jar:na]
at org.apache.xml.security.c14n.implementations.CanonicalizerBase.engineCanonicalizeSubTree(Unknown Source) [xmls
ec-1.4.3.jar:na]
at org.apache.xml.security.c14n.implementations.Canonicalizer20010315Excl.engineCanonicalizeSubTree(Unknown Sourc
e) [xmlsec-1.4.3.jar:na]
at org.apache.xml.security.c14n.implementations.Canonicalizer20010315Excl.engineCanonicalizeSubTree(Unknown Sourc
e) [xmlsec-1.4.3.jar:na]
at org.apache.xml.security.c14n.Canonicalizer.canonicalizeSubtree(Unknown Source) [xmlsec-1.4.3.jar:na]
at org.apache.xml.security.signature.SignedInfo.signInOctectStream(Unknown Source) [xmlsec-1.4.3.jar:na]
at org.apache.xml.security.signature.XMLSignature.checkSignatureValue(Unknown Source) [xmlsec-1.4.3.jar:na]
at org.opensaml.xml.signature.SignatureValidator.validate(SignatureValidator.java:68) [xmltooling-1.2.1.jar:na]
at org.opensaml.xml.signature.impl.BaseSignatureTrustEngine.verifySignature(BaseSignatureTrustEngine.java:141) [x
mltooling-1.2.1.jar:na]
at org.opensaml.xml.signature.impl.BaseSignatureTrustEngine.validate(BaseSignatureTrustEngine.java:99) [xmltoolin
g-1.2.1.jar:na]
at org.opensaml.xml.signature.impl.ExplicitKeySignatureTrustEngine.validate(ExplicitKeySignatureTrustEngine.java:
99) [xmltooling-1.2.1.jar:na]
at org.opensaml.xml.signature.impl.ExplicitKeySignatureTrustEngine.validate(ExplicitKeySignatureTrustEngine.java:
48) [xmltooling-1.2.1.jar:na]
at org.opensaml.xml.signature.impl.ChainingSignatureTrustEngine.validate(ChainingSignatureTrustEngine.java:67) [x
mltooling-1.2.1.jar:na]
at org.opensaml.xml.signature.impl.ChainingSignatureTrustEngine.validate(ChainingSignatureTrustEngine.java:36) [x
mltooling-1.2.1.jar:na]
at org.opensaml.ws.security.provider.BaseTrustEngineRule.evaluate(BaseTrustEngineRule.java:103) [openws-1.3.0.jar
:na]
at org.opensaml.ws.security.provider.BaseTrustEngineRule.evaluate(BaseTrustEngineRule.java:90) [openws-1.3.0.jar:
na]
at org.opensaml.common.binding.security.SAMLProtocolMessageXMLSignatureSecurityPolicyRule.doEvaluate(SAMLProtocol
MessageXMLSignatureSecurityPolicyRule.java:127) [opensaml-2.3.1.jar:na]
at org.opensaml.common.binding.security.SAMLProtocolMessageXMLSignatureSecurityPolicyRule.evaluate(SAMLProtocolMe
ssageXMLSignatureSecurityPolicyRule.java:106) [opensaml-2.3.1.jar:na]
at org.opensaml.ws.security.provider.BasicSecurityPolicy.evaluate(BasicSecurityPolicy.java:50) [openws-1.3.0.jar:
na]
at org.opensaml.ws.message.decoder.BaseMessageDecoder.processSecurityPolicy(BaseMessageDecoder.java:110) [openws-
1.3.0.jar:na]
at org.opensaml.ws.message.decoder.BaseMessageDecoder.decode(BaseMessageDecoder.java:79) [openws-1.3.0.jar:na]
at org.opensaml.saml2.binding.decoding.BaseSAML2MessageDecoder.decode(BaseSAML2MessageDecoder.java:69) [opensaml-
2.3.1.jar:na]
at edu.internet2.middleware.shibboleth.idp.profile.saml2.ArtifactResolution.decodeRequest(ArtifactResolution.java
:187) [shibboleth-identityprovider-2.1.5.jar:na]
at edu.internet2.middleware.shibboleth.idp.profile.saml2.ArtifactResolution.processRequest(ArtifactResolution.jav
a:96) [shibboleth-identityprovider-2.1.5.jar:na]
at edu.internet2.middleware.shibboleth.idp.profile.saml2.ArtifactResolution.processRequest(ArtifactResolution.jav
a:1) [shibboleth-identityprovider-2.1.5.jar:na]
at edu.internet2.middleware.shibboleth.common.profile.ProfileRequestDispatcherServlet.service(ProfileRequestDispa
tcherServlet.java:83) [shibboleth-common-1.1.4.jar:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) [servlet-api.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina.ja
r:na]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:na]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) [catalina.jar:na]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [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:102) [catalina.jar:na]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina.jar:na]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298) [catalina.jar:na]
at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190) [tomcat-coyote.jar:na]
at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291) [tomcat-coyote.jar:na]
at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:769) [tomcat-coyote.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:na]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) [catalina.jar:na]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [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:102) [catalina.jar:na]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina.jar:na]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298) [catalina.jar:na]
at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190) [tomcat-coyote.jar:na]
at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291) [tomcat-coyote.jar:na]
at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:769) [tomcat-coyote.jar:na]
at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:698) [tomcat-coyote.jar:na]
at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:891) [tomcat-coyote.jar:na]
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690) [tomcat-coyote.jar:na]
at java.lang.Thread.run(Thread.java:619) [na:1.6.0_18]
Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: CKR_SESSION_HANDLE_INVALID
at sun.security.pkcs11.wrapper.PKCS11.C_VerifyInit(Native Method) [sunpkcs11.jar:na]
at sun.security.pkcs11.P11Signature.initialize(P11Signature.java:290) [sunpkcs11.jar:na]
... 51 common frames omitted
Our Environment:
OS: Solaris 10 / Sparc
IDP-Version: 2.1.5
It seems to be temporary problem as I can see subsequent successfull
logins / assertions from the same user(s).
Had anyone noticed a similar problem?
Any help is greatly appreciated.
best regards
Harald Strack
--
Harald Strack, Dipl.Inf.(FH)
IT Development
ssystems
c/o todo GmbH
Alt-Moabit 60a
10555 Berlin
Tel: +49 30 805 78 - 101
http://www.ssystems.de
--
Harald Strack, Dipl.Inf.(FH)
IT Development
ssystems
c/o todo GmbH
Alt-Moabit 60a
10555 Berlin
Brent Putman
On 10/11/10 3:52 AM, Harald Strack wrote:
> Hi,
>
> we are receiving occasional complaints from users which get a
> opensaml::BindingException on a SP. On our IDP we could locate the
> following corresponding messages:
>
> Unable to resolve artifact(s) into a SAML response.
>
> Rejecting replayed artifact (AAQAArHKpA2t81ko0IOfkKP1rRnYERRsF5LAqcwPhdTr+ILixAOfFXJeLng=).
>
> caused by a:
>
> sun.security.pkcs11.wrapper.PKCS11Exception: CKR_SESSION_HANDLE_INVALID
>
> Details in the stack trace below.
>
>
Based on the stack trace, what's going on is that the IdP has issued a
SAML 2 artifact to the SP. The SP is then trying to resolve the
artifact with an ArtifactResolve message that is secured via an XML
Signature (rather than say client TLS, which we also support). The
verification of that XML Signature is then failing with this PKCS11
exception.
That's just background in case it wasn't clear. The culprit is the Sun
PKCS11 security provider that's being invoked here (as configured in
JAVA_HOME/jre/lib/security/java.security).
If you really want to resolve this and use the PKCS11 provider, you
probably need to ask on the Sun forums or lists. This error is several
layers of software below the Shibboleth IdP software.
Unless you really need PKCS11 support on the machine (e.g. using crypto
accelerator or something like that), you might try disabling the PKCS11
provider and just let it use the standard JRE providers that are there.
At least on the Solaris SPARC 10 machine I have access to, the PKCS11
one is first in default the provider list, so it's going to get used
instead of the others (for the services/algorithms that it supports).
security.provider.1=sun.security.pkcs11.SunPKCS11
${java.home}/lib/security/sunpkcs11-solaris.cfg
security.provider.2=sun.security.provider.Sun
security.provider.3=sun.security.rsa.SunRsaSign
security.provider.4=com.sun.net.ssl.internal.ssl.Provider
security.provider.5=com.sun.crypto.provider.SunJCE
security.provider.6=sun.security.jgss.SunProvider
security.provider.7=com.sun.security.sasl.Provider
security.provider.8=org.jcp.xml.dsig.internal.dom.XMLDSigRI
security.provider.9=sun.security.smartcardio.SunPCSC
>
>
> Our Environment:
>
> OS: Solaris 10 / Sparc
> IDP-Version: 2.1.5
>
> It seems to be temporary problem as I can see subsequent successfull
> logins / assertions from the same user(s).
You didn't mention whether the SP was Shibboleth or not, but I was under
the impression that the Shib SP defaulted to client TLS rather than XML
signing in this case. So this wouldn't be that common to see. And
artifacts aren't common either. So not surprising that you see other
messages process successfully for the same users.
--Brent