IdP 3.1.1 Unable to resolve outbound message endpoint

Tue Mar 31 22:09:04 EDT 2015

Hi,

I am using Shibboleth IdP version 3.1.1 on RHEL 6.6 with Oracle JDK
1.8.0_40 and Jetty 9.2.10.

This is a new deployment and not an upgrade.

After deployment into Jetty I was able to start Jetty and see the IdP
context started with no issues.

Next I configured to have some metadata for a test SP loaded from a
static file and restarted Jetty, again with no issues.

As my next step I pursued Password authentication using LDAP. Since it
is the configured default I simply set the relevant properties in
conf/ldap.properties.

I have not yet made any changes to relying-party.xml or dealt with any
attribute resolving or filtering, thinking I would do that after I saw
authentication "work".

After restarting Jetty I do not see any errors but when I cause a
SAML2 Redirect SSO flow I immediately see in the browser "Web Login
Service - Unable to Respond" and I find this in the log:

2015-03-31 18:48:23,910 - DEBUG
[net.shibboleth.idp.profile.audit.impl.PopulateAuditContext:198] -
Profile Action PopulateAuditContext: Skipping field 'p' not included
in audit format
2015-03-31 18:48:23,910 - DEBUG
[net.shibboleth.idp.profile.audit.impl.PopulateAuditContext:198] -
Profile Action PopulateAuditContext: Skipping field 'pasv' not
included in audit format
2015-03-31 18:48:23,911 - DEBUG
[net.shibboleth.idp.profile.audit.impl.PopulateAuditContext:220] -
Profile Action PopulateAuditContext: Adding 1 value for field 'I'
2015-03-31 18:48:23,917 - DEBUG
[net.shibboleth.idp.profile.audit.impl.PopulateAuditContext:220] -
Profile Action PopulateAuditContext: Adding 1 value for field 'b'
2015-03-31 18:48:23,917 - DEBUG
[net.shibboleth.idp.profile.audit.impl.PopulateAuditContext:198] -
Profile Action PopulateAuditContext: Skipping field 'D' not included
in audit format
2015-03-31 18:48:23,917 - DEBUG
[net.shibboleth.idp.profile.audit.impl.PopulateAuditContext:198] -
Profile Action PopulateAuditContext: Skipping field 'fauth' not
included in audit format
2015-03-31 18:48:23,932 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.saml.common.binding.impl.CheckMessageVersionHandler'
on INBOUND message context
2015-03-31 18:48:23,933 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:23,938 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.saml.saml1.binding.impl.SAML1ArtifactRequestIssuerHandler'
on INBOUND message context
2015-03-31 18:48:23,939 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:23,943 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.saml.common.binding.impl.SAMLProtocolAndRoleHandler'
on INBOUND message context
2015-03-31 18:48:23,943 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:23,951 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.saml.common.binding.impl.SAMLMetadataLookupHandler'
on INBOUND message context
2015-03-31 18:48:23,952 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:23,959 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.saml.common.binding.impl.SAMLAddAttributeConsumingServiceHandler'
on INBOUND message context
2015-03-31 18:48:23,959 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:23,963 - DEBUG
[net.shibboleth.idp.saml.profile.impl.InitializeRelyingPartyContextFromSAMLPeer:132]
- Profile Action InitializeRelyingPartyContextFromSAMLPeer: Attaching
RelyingPartyContext based on SAML peer
https://my.test-sp.edu/shibboleth (sk: real and valid entityID
actually appears here)
2015-03-31 18:48:23,968 - DEBUG
[net.shibboleth.idp.relyingparty.impl.DefaultRelyingPartyConfigurationResolver:284]
- Resolving relying party configuration
2015-03-31 18:48:23,969 - DEBUG
[net.shibboleth.idp.relyingparty.impl.DefaultRelyingPartyConfigurationResolver:305]
- No relying party configurations are applicable, returning the
default configuration shibboleth.DefaultRelyingParty
2015-03-31 18:48:23,969 - DEBUG
[net.shibboleth.idp.profile.impl.SelectRelyingPartyConfiguration:136]
- Profile Action SelectRelyingPartyConfiguration: Found relying party
configuration shibboleth.DefaultRelyingParty for request
2015-03-31 18:48:23,972 - DEBUG
[net.shibboleth.idp.profile.audit.impl.PopulateAuditContext:220] -
Profile Action PopulateAuditContext: Adding 1 value for field 'IDP'
2015-03-31 18:48:23,972 - DEBUG
[net.shibboleth.idp.profile.audit.impl.PopulateAuditContext:220] -
Profile Action PopulateAuditContext: Adding 1 value for field 'SP'
2015-03-31 18:48:24,020 - DEBUG
[net.shibboleth.idp.profile.interceptor.impl.PopulateProfileInterceptorContext:126]
- Profile Action PopulateProfileInterceptorContext: Installing flow
intercept/security-policy/saml2-sso into interceptor context
2015-03-31 18:48:24,081 - DEBUG
[net.shibboleth.idp.profile.interceptor.impl.FilterFlowsByNonBrowserSupport:52]
- Profile Action FilterFlowsByNonBrowserSupport: Request does not have
non-browser requirement, nothing to do
2015-03-31 18:48:24,086 - DEBUG
[net.shibboleth.idp.profile.interceptor.impl.SelectProfileInterceptorFlow:101]
- Profile Action SelectProfileInterceptorFlow: Checking flow
intercept/security-policy/saml2-sso for applicability...
2015-03-31 18:48:24,086 - DEBUG
[net.shibboleth.idp.profile.interceptor.impl.SelectProfileInterceptorFlow:84]
- Profile Action SelectProfileInterceptorFlow: Selecting flow
intercept/security-policy/saml2-sso
2015-03-31 18:48:24,163 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.saml.common.binding.security.impl.ReceivedEndpointSecurityHandler'
on INBOUND message context
2015-03-31 18:48:24,163 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:24,170 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.saml.common.binding.security.impl.MessageReplaySecurityHandler'
on INBOUND message context
2015-03-31 18:48:24,171 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:24,176 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.saml.common.binding.security.impl.MessageLifetimeSecurityHandler'
on INBOUND message context
2015-03-31 18:48:24,177 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:24,184 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.saml.saml2.binding.security.impl.SAML2AuthnRequestsSignedSecurityHandler'
on INBOUND message context
2015-03-31 18:48:24,184 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:24,195 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.saml.common.binding.security.impl.SAMLProtocolMessageXMLSignatureSecurityHandler'
on INBOUND message context
2015-03-31 18:48:24,195 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:24,202 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.saml.saml2.binding.security.impl.SAML2HTTPRedirectDeflateSignatureSecurityHandler'
on INBOUND message context
2015-03-31 18:48:24,203 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:24,208 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.saml.saml2.binding.security.impl.SAML2HTTPPostSimpleSignSecurityHandler'
on INBOUND message context
2015-03-31 18:48:24,210 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:24,217 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
of type 'org.opensaml.messaging.handler.impl.CheckMandatoryIssuer' on
INBOUND message context
2015-03-31 18:48:24,217 - DEBUG
[net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] -
Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler
on message context containing a message of type
'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2015-03-31 18:48:24,221 - DEBUG
[net.shibboleth.idp.profile.interceptor.impl.WriteProfileInterceptorResultToStorage:68]
- Profile Action WriteProfileInterceptorResultToStorage: No results
available from interceptor context, nothing to store
2015-03-31 18:48:24,221 - DEBUG
[net.shibboleth.idp.profile.interceptor.impl.FilterFlowsByNonBrowserSupport:52]
- Profile Action FilterFlowsByNonBrowserSupport: Request does not have
non-browser requirement, nothing to do
2015-03-31 18:48:24,222 - 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
2015-03-31 18:48:24,222 - DEBUG
[net.shibboleth.idp.profile.interceptor.impl.SelectProfileInterceptorFlow:80]
- Profile Action SelectProfileInterceptorFlow: No flows available to
choose from
2015-03-31 18:48:24,227 - DEBUG
[net.shibboleth.idp.saml.profile.impl.InitializeOutboundMessageContext:149]
- Profile Action InitializeOutboundMessageContext: Initialized
outbound message context
2015-03-31 18:48:24,241 - DEBUG
[net.shibboleth.idp.saml.profile.impl.PopulateBindingAndEndpointContexts:367]
- Profile Action PopulateBindingAndEndpointContexts: Attempting to
resolve endpoint of type
{urn:oasis:names:tc:SAML:2.0:metadata}AssertionConsumerService for
outbound message
2015-03-31 18:48:24,242 - DEBUG
[net.shibboleth.idp.saml.profile.impl.PopulateBindingAndEndpointContexts:505]
- Profile Action PopulateBindingAndEndpointContexts: Populating
template endpoint for resolution from SAML AuthnRequest
2015-03-31 18:48:24,243 - WARN
[net.shibboleth.idp.saml.profile.impl.PopulateBindingAndEndpointContexts:402]
- Profile Action PopulateBindingAndEndpointContexts: Unable to resolve
outbound message endpoint

What error condition am I actually hitting and how might I have seen
it from the log?

Was my deployment methodology (as it were) incorrect and should I have
attempted to configure attribute resolution and filtering away from
the defaults before checking that I could make authentication work? Or
(more likely), have I just missed something simple?

Thanks,

Scott K