Shibboleth Suddenly Stops Working

Shibboleth Suddenly Stops Working

by Ali Hastie -
Number of replies: 1

Currently using Moodle 3.5 version with Shibboleth authentication, which has suddenly stopped working with the following when we try to login:

Web Login Service - Unable to Respond

The login service was unable to identify a compatible way to respond to the requested application. This is generally to due to a misconfiguration on the part of the application and should be reported to the application's support team or owner.

Our administrator has sent the follow when logging is set to debug:

  

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:174] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.common.binding.security.impl.MessageReplaySecurityHandler' on INBOUND message context 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:195] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl' 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:174] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.common.binding.security.impl.MessageLifetimeSecurityHandler' on INBOUND message context 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:195] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl' 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:174] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.saml2.binding.security.impl.SAML2AuthnRequestsSignedSecurityHandler' on INBOUND message context 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:195] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl' 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:174] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.common.binding.security.impl.SAMLProtocolMessageXMLSignatureSecurityHandler' on INBOUND message context 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:195] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl' 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:174] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.saml2.binding.security.impl.SAML2HTTPRedirectDeflateSignatureSecurityHandler' on INBOUND message context 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:195] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl' 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:174] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.saml2.binding.security.impl.SAML2HTTPPostSimpleSignSecurityHandler' on INBOUND message context 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:195] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl' 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:174] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.messaging.handler.impl.CheckMandatoryIssuer' on INBOUND message context 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:195] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl' 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.interceptor.impl.WriteProfileInterceptorResultToStorage:68] - Profile Action WriteProfileInterceptorResultToStorage: No results available from interceptor context, nothing to store 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.interceptor.impl.FilterFlowsByNonBrowserSupport:52] - Profile Action FilterFlowsByNonBrowserSupport: Request does not have non-browser requirement, nothing to do 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.interceptor.impl.SelectProfileInterceptorFlow:65] - Profile Action SelectProfileInterceptorFlow: Moving completed flow intercept/security-policy/saml2-sso to completed set, selecting next one 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.profile.interceptor.impl.SelectProfileInterceptorFlow:80] - Profile Action SelectProfileInterceptorFlow: No flows available to choose from 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.saml.profile.impl.InitializeOutboundMessageContext:149] - Profile Action InitializeOutboundMessageContext: Initialized outbound message context 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.saml.profile.impl.PopulateBindingAndEndpointContexts:375] - Profile Action PopulateBindingAndEndpointContexts: Attempting to resolve endpoint of type 

{urn:oasis:names:tc:SAML:2.0:metadata

AssertionConsumerService for outbound message 

2020-04-16 16:59:59,177 - DEBUG [net.shibboleth.idp.saml.profile.impl.PopulateBindingAndEndpointContexts:516] - Profile Action PopulateBindingAndEndpointContexts: Populating template endpoint for resolution from SAML AuthnRequest 

2020-04-16 16:59:59,177 - WARN [net.shibboleth.idp.saml.profile.impl.PopulateBindingAndEndpointContexts:410] - Profile Action PopulateBindingAndEndpointContexts: Unable to resolve outbound message endpoint for relying party 'https://engage.elearning.sruc.ac.uk': EndpointCriterion [type=

{urn:oasis:names:tc:SAML:2.0:metadata} 

AssertionConsumerService, Binding=urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST, Location=https://engage.elearning.sruc.ac.uk/Shibboleth.sso/SAML2/POST, trusted=false] 

2020-04-16 16:59:59,177 - WARN [org.opensaml.profile.action.impl.LogEvent:105] - A non-proceed event occurred while processing the request: EndpointResolutionFailed 



Average of ratings: -
In reply to Ali Hastie

Re: Shibboleth Suddenly Stops Working

by Leon Stringer -
Picture of Core developers Picture of Particularly helpful Moodlers

In my Shibboleth experience "suddenly stopped working" often means metadata expiry, so the first thing I'd check is that the identity provider (IdP) has the current metadata for the service provider (SP), i.e. Moodle in this case.

The logging output appears to be the IdP complaining that it can't match an SP AssertionConsumerService URL with that listed in the SP's metadata.

I'm guessing something like this is happening:

  1. The unauthenticated user goes to Moodle and tries to log in.
  2. Moodle redirects the user to the IdP for authentication
  3. The IdP authenticates the user.
  4. The IdP then wants to send user information to the SP via the URL that the SP provided in step 2. But the IdP can't match this URL to any it knows about so the process fails.
2020-04-16 16:59:59,177 - WARN [net.shibboleth.idp.profile.saml.impl.PopulateBindingAndEndpointContexts:410] - Profile Action PopulateBindingAndEndpointContexts: Unable to resolve outbound message endpoint for relying party 'https://engage.elearning.sruc.ac.uk': EndpointCriterion [type=
{urn:oasis:names:tc:SAML:2.0:metadata}
AssertionConsumerService, Binding=urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST, Location=https://engage.elearning.sruc.ac.uk/Shibboleth.sso/SAML2/POST, trusted=false]

So I'd 1) check the SP's metadata making sure this lists an exactly matching AssertionConsumerService element, both the URL ("https://engage.elearning.sruc.ac.uk/Shibboleth.sso/SAML2/POST") and the binding ("urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST") must match, and 2) check the IdP has a current copy of the SP's metadata which contains this AssertionConsumerService.