By: Christopher Palmer user 12 Dec 2017 at 10:39 a.m. CST

4 Responses
Christopher Palmer gravatar

I went through the upgrade steps (with export and import scripts) to get from gluu 3.0.2 to 3.1.1.

I am getting a 503 Service Unavailable when accessing /identity/

I’ve tried restarting the services and can startup the 3.0.2 instance and access it ok.

I found a couple of errors in the logs that I thought maybe helpful. Note: I can perform ldapsearch just fine in 3.1.1.

GLUU.[root@sticky logs]# grep -A1 -m1 ERROR oxtrust.log
2017-12-12 00:21:52,873 ERROR [main] [org.xdi.util.security.PropertiesDecrypter] (PropertiesDecrypter.java:70) - Failed to decript 'bindPassword' property
org.xdi.util.security.StringEncrypter$EncryptionException: javax.crypto.IllegalBlockSizeException: Input length must be multiple of 8 when decrypting with padded cipher
GLUU.[root@sticky logs]# grep -A1 -m1 ERROR oxtrust_persistence.log 
2017-12-12 00:00:03,071 ERROR [main] [org.gluu.site.ldap.persistence.AbstractEntryManager] (AbstractEntryManager.java:1114) - Failed to convert json value '{"cacheProviderType": "IN_MEMORY", "memcachedConfiguration": {"servers":"localhost:11211", "maxOperationQueueLength":100000, "bufferSize":32768, "defaultPutExpiration":60, "connectionFactoryType": ""DEFAULT""}, "inMemoryConfiguration": {"defaultPutExpiration":60}}' to object: 
org.codehaus.jackson.map.JsonMappingException: Can not construct instance of org.xdi.service.cache.MemcachedConnectionFactoryType from String value '': value not one of declared Enum instance names

Also the stderr idp log shows:

GLUU.[root@sticky logs]# head -50 2017_12_12.stderrout.log
2017-12-12 15:46:00.092:INFO:oejs.Server:main: jetty-9.3.15.v20161220
2017-12-12 15:46:00.115:INFO:oejdp.ScanningAppProvider:main: Deployment monitor [file:///opt/gluu/jetty/idp/webapps/] at interval 1
2017-12-12 15:46:07.751:INFO:oeja.AnnotationConfiguration:main: Scanning elapsed time=6973ms
2017-12-12 15:46:07.808:INFO:idp:main: No Spring WebApplicationInitializer types detected on classpath
2017-12-12 15:46:07.990:WARN:oejs.SecurityHandler:main: ServletContext@o.e.j.w.WebAppContext@57baeedf{/idp,file:///opt/jetty-9.3/temp/jetty-localhost-8086-idp.war-_idp-any-8432134882703129128.dir/webapp/,STARTING}{/idp.war} has uncovered http methods for path: /*
2017-12-12 15:46:08.241:INFO:idp:main: Initializing Spring root WebApplicationContext
2017-12-12 15:46:35.183:WARN:oejw.WebAppContext:main: Failed startup of context o.e.j.w.WebAppContext@57baeedf{/idp,file:///opt/jetty-9.3/temp/jetty-localhost-8086-idp.war-_idp-any-8432134882703129128.dir/webapp/,UNAVAILABLE}{/idp.war}
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'shibboleth.MetadataResolverService' defined in URL [file:/opt/shibboleth-idp/system/conf/services-system.xml]: Invocation of init method failed; nested exception is net.shibboleth.utilities.java.support.component.ComponentInitializationException: Service 'shibboleth.MetadataResolverService': Unexpected error during initial load
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1578)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:545)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
        at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:776)
        at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:861)
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:541)
        at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:444)
        at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:326)
        at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:107)
        at org.eclipse.jetty.server.handler.ContextHandler.callContextInitialized(ContextHandler.java:843)
        at org.eclipse.jetty.servlet.ServletContextHandler.callContextInitialized(ServletContextHandler.java:533)
        at org.eclipse.jetty.server.handler.ContextHandler.startContext(ContextHandler.java:816)
        at org.eclipse.jetty.servlet.ServletContextHandler.startContext(ServletContextHandler.java:345)
        at org.eclipse.jetty.webapp.WebAppContext.startWebapp(WebAppContext.java:1404)
        at org.eclipse.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1366)
        at org.eclipse.jetty.server.handler.ContextHandler.doStart(ContextHandler.java:778)
        at org.eclipse.jetty.servlet.ServletContextHandler.doStart(ServletContextHandler.java:262)
        at org.eclipse.jetty.webapp.WebAppContext.doStart(WebAppContext.java:520)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
        at org.eclipse.jetty.deploy.bindings.StandardStarter.processBinding(StandardStarter.java:41)
        at org.eclipse.jetty.deploy.AppLifeCycle.runBindings(AppLifeCycle.java:188)
        at org.eclipse.jetty.deploy.DeploymentManager.requestAppGoal(DeploymentManager.java:499)
        at org.eclipse.jetty.deploy.DeploymentManager.addApp(DeploymentManager.java:147)
        at org.eclipse.jetty.deploy.providers.ScanningAppProvider.fileAdded(ScanningAppProvider.java:180)
        at org.eclipse.jetty.deploy.providers.WebAppProvider.fileAdded(WebAppProvider.java:452)
        at org.eclipse.jetty.deploy.providers.ScanningAppProvider$1.fileAdded(ScanningAppProvider.java:64)
        at org.eclipse.jetty.util.Scanner.reportAddition(Scanner.java:610)
        at org.eclipse.jetty.util.Scanner.reportDifferences(Scanner.java:529)
        at org.eclipse.jetty.util.Scanner.scan(Scanner.java:392)
        at org.eclipse.jetty.util.Scanner.doStart(Scanner.java:313)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
        at org.eclipse.jetty.deploy.providers.ScanningAppProvider.doStart(ScanningAppProvider.java:150)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
        at org.eclipse.jetty.deploy.DeploymentManager.startAppProvider(DeploymentManager.java:561)
        at org.eclipse.jetty.deploy.DeploymentManager.doStart(DeploymentManager.java:236)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
        at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:131)
        at org.eclipse.jetty.server.Server.start(Server.java:422)
<snip>

By Michael Schwartz staff 12 Dec 2017 at 4:03 p.m. CST

Michael Schwartz gravatar

Arvind, any thoughts?

By Arvind Tomar staff 12 Dec 2017 at 11:10 p.m. CST

Arvind Tomar gravatar

Hi Christopher Palmer , mike

GLUU.[root@sticky logs]# grep -A1 -m1 ERROR oxtrust_persistence.log 2017-12-12 00:00:03,071 ERROR [main] [org.gluu.site.ldap.persistence.AbstractEntryManager] (AbstractEntryManager.java:1114) - Failed to convert json value '{"cacheProviderType": "IN_MEMORY", "memcachedConfiguration": {"servers":"localhost:11211", "maxOperationQueueLength":100000, "bufferSize":32768, "defaultPutExpiration":60, "connectionFactoryType": ""DEFAULT""}, "inMemoryConfiguration": {"defaultPutExpiration":60}}' to object: org.codehaus.jackson.map.JsonMappingException: Can not construct instance of org.xdi.service.cache.MemcachedConnectionFactoryType from String value '': value not one of declared Enum instance names

it was an error in JSON creation I have fixed it and updated the code it now it will work now.

Christopher, please try again from start with export and import.

Thank Arvind Tomar

By Christopher Palmer user 13 Dec 2017 at 11:27 a.m. CST

Christopher Palmer gravatar

Thanks Arvind and Mike. I did as you suggested with the updated script and have now got past the 503 error for the homepage. I am now seeing a new 503 error when I try to use SSO to authenticate with Gluu's idp. When I get redirected to Gluu, I got: HTTP ERROR: 503

Problem accessing /idp/profile/SAML2/Unsolicited/SSO. Reason:

Service Unavailable

The 'idp' service start logs:

2017-12-13 17:10:23.808:INFO:idp:main: Initializing Spring root WebApplicationContext
2017-12-13 17:10:47.776:WARN:oejw.WebAppContext:main: Failed startup of context o.e.j.w.WebAppContext@57baeedf{/idp,file:///opt/jetty-9.3/temp/jetty-localhost-8086-idp.war-_idp-any-4487237923635630056.dir/webapp/,UNAVAILABLE}{/idp.war}
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'shibboleth.MetadataResolverService' defined in URL [file:/opt/shibboleth-idp/system/conf/services-system.xml]: Invocation of init method failed; nested exception is net.shibboleth.utilities.java.support.component.ComponentInitializationException: Service 'shibboleth.MetadataResolverService': Unexpected error during initial load
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1578)
<snip>

Further down...

GLUU.[root@sticky logs]# grep -a1 written 2017_12_13.stderrout.log
Caused by: 
net.shibboleth.utilities.java.support.resolver.ResolverException: Filepath /opt/shibboleth-idp/metadata/AACC20ED4FA1F8D70002B069FE450006118F0E68-sp-metadata.xml exists but can not be written to by this user
    at org.opensaml.saml.metadata.resolver.impl.FileBackedHTTPMetadataResolver.validateBackupFile(FileBackedHTTPMetadataResolver.java:267)

Indeed, the imported trust relationship XML files were owned by 'root' (not 'jetty'). I am OK with adjusting these permissions and restarting the services, but need to also mention that:

I also see in the GUI that I now have TWO "gluu on SP appliance" trust relationships. Should I delete one? If so, should it be the imported (older) one? (I think it's the one that has the root permissions).

By Christopher Palmer user 13 Dec 2017 at 1:48 p.m. CST

Christopher Palmer gravatar

The following seems to have got me going (no more 503 seen):

# cd /opt/shibboleth-idp/metadata/
# chmod 644 A*.xml
# chown jetty:jetty A*.xml idp-metadata.xml

(delete the "old"/imported "gluu SP on appliance" trust relationship via the GUI)

# service idp restart

I do still see the following in the identity log when that service is starting:

2017-12-14 17:30:41,107 INFO  [main] [org.gluu.oxtrust.config.ConfigurationFactory] (ConfigurationFactory.java:420) - ########## ldapFileName = /etc/gluu/conf/ox-ldap.properties
2017-12-14 17:30:41,272 ERROR [main] [org.xdi.util.security.PropertiesDecrypter] (PropertiesDecrypter.java:70) - Failed to decript 'bindPassword' property
org.xdi.util.security.StringEncrypter$EncryptionException: javax.crypto.IllegalBlockSizeException: Input length must be multiple of 8 when decrypting with padded cipher
    at org.xdi.util.security.StringEncrypter.decrypt(StringEncrypter.java:214) ~[oxcore-util-3.1.1.Final.jar:?]
<snip>

...yet things do seem to be working.

Thanks!