Error Response from ShibbolethSP SLO endpoint

Mon Dec 12 13:19:01 GMT 2011

Hi,
I am trying to get a front-channel SLO scenario working. I am sending signed SAML 2.0 Logout Request messages to the /Shibboleth.sso/SLO/Redirect endpoint of a Win32 ShibbolethSP 2.4.3 installation, but all I get in return is a SAML 2.0 Response with an error message ("Error processing request.").
>From the shibd.log it appears that the Logout Request message gets correctly parsed and verified, and then the error response is produced, without any explicit reason.

Here is the content of the shibd.log.
Thanks in advance for any help!

2011-12-09 17:34:42 DEBUG Shibboleth.Listener [1]: dispatching message (default/SLO/Redirect)
2011-12-09 17:34:42 DEBUG OpenSAML.MessageDecoder.SAML2Redirect [1]: validating input
2011-12-09 17:34:42 DEBUG OpenSAML.MessageDecoder.SAML2Redirect [1]: decoded SAML message:
<?xml version="1.0" encoding="UTF-8"?><saml2p:LogoutRequest xmlns:saml2p="urn:oasis:names:tc:SAML:2.0:protocol" Destination="https://sp-host/shib-sp-test/protectedUP/Shibboleth.sso/SLO/Redirect" ID="_d15fb2a308418aff404969db545e5a98" IssueInstant="2011-12-09T16:34:42.949Z" Version="2.0"><saml2:Issuer xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion" Format="urn:oasis:names:tc:SAML:2.0:nameid-format:entity">TheIssuer</saml2:Issuer><saml2:NameID xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion" Format="urn:oasis:names:tc:SAML:2.0:nameid-format:transient">_5f87df2146929ba4d4fbd2fef003d403</saml2:NameID></saml2p:LogoutRequest>
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject.Builder [1]: located XMLObjectBuilder for element name: saml2p:LogoutRequest
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling DOM element (saml2p:LogoutRequest)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling attributes for DOM element (saml2p:LogoutRequest)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing generic attribute
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing generic attribute
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing generic attribute
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing generic attribute
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: found namespace declaration, adding it to the list of namespaces on the XMLObject
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling child nodes of DOM element (saml2p:LogoutRequest)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject.Builder [1]: located XMLObjectBuilder for element name: saml2:Issuer
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling child element (saml2:Issuer)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling DOM element (saml2:Issuer)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling attributes for DOM element (saml2:Issuer)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing generic attribute
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: found namespace declaration, adding it to the list of namespaces on the XMLObject
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling child nodes of DOM element (saml2:Issuer)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing text content at position (0)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject.Builder [1]: located XMLObjectBuilder for element name: saml2:NameID
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling child element (saml2:NameID)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling DOM element (saml2:NameID)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling attributes for DOM element (saml2:NameID)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing generic attribute
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: found namespace declaration, adding it to the list of namespaces on the XMLObject
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling child nodes of DOM element (saml2:NameID)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing text content at position (0)
2011-12-09 17:34:42 DEBUG OpenSAML.MessageDecoder.SAML2 [1]: extracting issuer from SAML 2.0 protocol message
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject.Builder [1]: located XMLObjectBuilder for element name: saml2:Issuer
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling DOM element (saml2:Issuer)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling attributes for DOM element (saml2:Issuer)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing generic attribute
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: found namespace declaration, adding it to the list of namespaces on the XMLObject
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling child nodes of DOM element (saml2:Issuer)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing text content at position (0)
2011-12-09 17:34:42 DEBUG OpenSAML.MessageDecoder.SAML2 [1]: message from (TheIssuer)
2011-12-09 17:34:42 DEBUG OpenSAML.MessageDecoder.SAML2 [1]: searching metadata for message issuer...
2011-12-09 17:34:42 DEBUG OpenSAML.SecurityPolicyRule.MessageFlow [1]: evaluating message flow policy (replay checking on, expiration 60)
2011-12-09 17:34:42 DEBUG XMLTooling.StorageService [1]: inserted record (_d15fb2a308418aff404969db545e5a98) in context (MessageFlow) with expiration (1323448722)
2011-12-09 17:34:42 DEBUG XMLTooling.TrustEngine.ExplicitKey [1]: attempting to validate signature with the peer's credentials
2011-12-09 17:34:42 DEBUG XMLTooling.TrustEngine.ExplicitKey [1]: signature validated with public key
2011-12-09 17:34:42 DEBUG OpenSAML.SecurityPolicyRule.SimpleSigning [1]: signature verified against message issuer
2011-12-09 17:34:42 DEBUG Shibboleth.SessionCache [1]: searching for session (_1d26a69912cdd73f1dc9701be20868de)
2011-12-09 17:34:42 DEBUG Shibboleth.SessionCache [1]: reconstituting session and checking validity
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling DOM element (saml2:NameID)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling attributes for DOM element (saml2:NameID)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing generic attribute
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing generic attribute
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing generic attribute
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: found namespace declaration, adding it to the list of namespaces on the XMLObject
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: unmarshalling child nodes of DOM element (saml2:NameID)
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: processing text content at position (0)
2011-12-09 17:34:42 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]: validating input
2011-12-09 17:34:42 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]: marshalling, deflating, base64-encoding the message
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: starting to marshal samlp:LogoutResponse
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: creating root element to marshall
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: marshalling namespace attributes for XMLObject
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: marshalling text and child elements for XMLObject
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: starting to marshalling saml:Issuer
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: creating root element to marshall
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: marshalling namespace attributes for XMLObject
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: marshalling text and child elements for XMLObject
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: caching DOM for XMLObject
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: starting to marshalling samlp:Status
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: creating root element to marshall
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: marshalling namespace attributes for XMLObject
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: marshalling text and child elements for XMLObject
2011-12-09 17:34:42 DEBUG XMLTooling.XMLObject [1]: starting to marshalling samlp:StatusCode
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: creating root element to marshall
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: marshalling namespace attributes for XMLObject
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: marshalling text and child elements for XMLObject
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: starting to marshalling samlp:StatusCode
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: creating root element to marshall
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: marshalling namespace attributes for XMLObject
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: marshalling text and child elements for XMLObject
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: caching DOM for XMLObject
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: caching DOM for XMLObject
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: starting to marshalling samlp:StatusMessage
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: creating root element to marshall
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: marshalling namespace attributes for XMLObject
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: marshalling text and child elements for XMLObject
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: caching DOM for XMLObject
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: caching DOM for XMLObject
2011-12-09 17:34:43 DEBUG XMLTooling.XMLObject [1]: caching DOM for XMLObject (document is bound)
2011-12-09 17:34:43 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]: marshalled message:
<samlp:LogoutResponse xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" Destination="https://myhost/MySLOApp/Logout" ID="_a62a85412843b509ec9f7c252a9474e7" InResponseTo="_d15fb2a308418aff404969db545e5a98" IssueInstant="2011-12-09T16:34:42Z" Version="2.0"><saml:Issuer xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">TheServiceProvider</saml:Issuer><samlp:Status><samlp:StatusCode Value="urn:oasis:names:tc:SAML:2.0:status:Requester"><samlp:StatusCode Value="urn:oasis:names:tc:SAML:2.0:status:RequestDenied"/></samlp:StatusCode><samlp:StatusMessage>Error processing request.</samlp:StatusMessage></samlp:Status></samlp:LogoutResponse>
2011-12-09 17:34:43 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]: signing the message
2011-12-09 17:34:43 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]: message encoded, sending redirect to client 

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://shibboleth.net/pipermail/users/attachments/20111212/10cb44d1/attachment.html 