Startup Issues

Basic Troubleshooting

...

The core logs consist of:

• The IdP process log, usually in idp.home/logs/idp-process.log (warnings and errors will be mirrored to idp.home/logs/idp-warn.log), is the primary troubleshooting resource for most problems. It should be the first place you look.

• A servlet container log from Tomcat, Jetty, etc. This is usually NOT all that useful unless the IdP is actually refusing to initialize and start up at all, but may be important in those cases. Note that if the Status page is viewable, that likely means the IdP started properly.

• A web server log in the case that you are proxying traffic from Apache or the like. This is also probably not involved unless the problem is very low-level and involves connectivity to the system.

• Web access logs, which track requests to the web server. These will be wherever traffic is handled (servlet container, Apache, etc.) and help with understanding what clients are asking for. This can help diagnose issues with the advertised locations for IdP functionality.

• Back-end logs of authentication and attribute sources may also be necessary in some cases, but most of the time the IdP should provide enough in its own log to indicate what the problems are.

Slow startup time

There are two known reasons for experiencing unusually slow startup: using Tomcat in certain ways and a blocking PRNG. Taken in order:

...

Traditionally this has been viewed as less safe. There are alternate views of this. The Shibboleth Project does not take an official position on this question.

Common Error Screens

The login service was unable to identify a compatible way to respond to the requested application...

This is a human translation of the EndpointResolutionFailed event in the IdP that triggers when the check between the AssertionConsumerServiceURL in an SP's request is not in the SP's metadata, so the IdP fails the request in accordance with the standard's requirement to validate the response location.

Most SAML SPs, and certainly most or all Shibboleth SPs, will include a full AssertionConsumerServiceURL attribute in their <AuthnRequest> message to the IdP. The value of the URL in a Shibboleth SP is determined by the computed request URL that led to the issuance of the request and is primarily a function of web server configuration (on Apache) or the SP's <ISAPI> site mapping configuration (on IIS).

Whatever its set to, that URL generally has to be one of the <AssertionConsumerService> endpoints in the SP's metadata used by the IdP or this error message is returned by default in response to the error and the IdP log records the problem.

As an IdP operator you either have bad metadata, or you have a broken SP, and unless you manage the metadata yourself (likely in the case of a commercial SP), it's not your problem to solve. Only the SP operator knows whether the URL is valid, so you may have to update the metadata or they will have to stop generating requests including the bad URL. The cause of a bad URL is generally a failure to properly configure a web server running the SP to account for local virtualization, load balancing, etc. It could also simply be a failure to update metadata to reflect a change that the SP deployer has made.

Common Log Messages

org.springframework.webflow.conversation.impl.LockTimeoutException: Unable to acquire conversation lock after 30 seconds

...

The first time the status page is accessed after starting the IdP, the following log message will be seen:

...

logs/idp-warn.log

ERROR [org.apache.velocity:96] - ResourceManager : unable to find resource 'status.vm' in any resource loader.

...

If the default login UI is changed from a Velocity template to a JSP, the following error will be seen at least once:

...

logs/idp-warn.log

ERROR [org.apache.velocity:96] - ResourceManager : unable to find resource 'login.vm' in any resource loader.

...

IdPs that consume metadata using the FileBackedHTTPMetadataProvider regularly download metadata from an external metadata source. The IdP has no control over the size of that metadata file, and it may have sufficiently increased in size from one download to the next that the IdP cannot process the later file. Since the IdP stores the previous file, it continues to use that until the metadata it contains expires (perhaps a couple of weeks after the initial out-of-memory error) at which point the IdP stops recognizing SPs. Re-starting the IdP temporarily resolves the issue because it allows the IdP to download new metadata until the next time it runs out of memory.

Symptoms include the idp-warn.log showing entries like this:

...

logs/idp-warn.log

2017-01-16 14:02:16,700 - DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractReloadingMetadataResolver:380] - Metadata Resolver FileBackedHTTPMetadataResolver UKfederationMetadata: Unmarshalling metadata from 'http://metadata.ukfederation.org.uk/ukfederation-metadata.xml'
2017-01-16 14:02:22,323 - ERROR [net.shibboleth.utilities.java.support.service.AbstractReloadableService:188] - Service 'shibboleth.MetadataResolverService': Unexpected error during initial load {} org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'ShibbolethMetadata': Cannot create inner bean

...

<Pattern>%date{ISO8601} - %level [%logger:%line] - %msg%n%ex{short}</Pattern>

with

<Pattern>%date{ISO8601} - %level [%logger:%line] - %msg%n%ex{full}</Pattern>

Can often provide a useful hint of where the fault has come from. For instance:

...