OMERO: Problem upgrading to ver 5.5.1

fhagemei · July 18, 2019, 2:43pm

Our system administrator is getting the following error while trying to start the application after an upgrade from 5.4.3 to 5.5.1. We need help resolving this, and we can provide log files and config files whichever needed. Searching through other posts with same error and following the instructions didn’t fix the problem.

[omero@bioimages OMERO.server]$ bin/omero admin start
Creating /home/omero/OMERO.server-5.5.1-ice36-b122/var/master
Initializing /home/omero/OMERO.server-5.5.1-ice36-b122/var/log
Creating /home/omero/OMERO.server-5.5.1-ice36-b122/var/registry
No descriptor given. Using etc/grid/default.xml
Waiting on startup. Use CTRL-C to exit
.............................
Failed to startup some components after 300 seconds
Calling "stop" on remaining components
Waiting on shutdown. Use CTRL-C to exit
......[omero@bioimages OMERO.server]$

Thanks!

mtbc · July 18, 2019, 2:41pm

This should be a fairly minor upgrade so I’m sorry to hear of your trouble. What does bin/omero admin diagnostics say? Are there useful errors reported in Blitz-0.log?

fhagemei · July 22, 2019, 6:09am

Thanks.

Here is blitz log:

2019-07-17 12:51:14,366 ERROR [                ome.services.blitz.Entry] (      main) Error on startup.

org.springframework.beans.factory.access.BootstrapException: Unable to return specified BeanFactory instance: factory key [OMERO.blitz], from group with resource name [classpath*:beanRefContext.xml]; nested exception is org.springframework.beans.factory.BeanCreationException:
Error creating bean with name 'OMERO.blitz' defined in URL [jar:file:/home/omero/OMERO.server-5.5.1-ice36-b122/lib/server/omero-blitz.jar!/beanRefContext.xml]: Cannot resolve reference to bean 'ome.server' while setting constructor argument; nested exception
is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'ome.server' defined in URL [jar:file:/home/omero/OMERO.server-5.5.1-ice36-b122/lib/server/omero-server.jar!/beanRefContext.xml]: Bean instantiation via constructor failed;
nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [ome.system.OmeroContext]: Constructor threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name
'internal-ome.api.RawPixelsStoreSubstituter' defined in URL [jar:file:/home/omero/OMERO.server-5.5.1-ice36-b122/lib/server/omero-server.jar!/ome/services/service-ome.api.RawPixelsStore.xml]: Cannot resolve reference to bean 'readOnlyStatus' while setting constructor
argument; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'readOnlyStatus' defined in class path resource [ome/services/startup.xml]: Bean instantiation via constructor failed; nested exception is
org.springframework.beans.BeanInstantiationException: Failed to instantiate [ome.services.util.ReadOnlyStatus]: Constructor threw exception; nested exception is ome.conditions.DatabaseBusyException: Cannot acquire connection

        at org.springframework.beans.factory.access.SingletonBeanFactoryLocator.useBeanFactory(SingletonBeanFactoryLocator.java:404) ~[spring-beans.jar:4.3.22.RELEASE]

        at ome.system.OmeroContext.getInstance(OmeroContext.java:202) ~[omero-common.jar:5.5.2]
        at ome.services.blitz.Entry.start(Entry.java:189) [omero-blitz.jar:5.5.3]
        at ome.services.blitz.Entry.main(Entry.java:146) [omero-blitz.jar:5.5.3]

 Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'readOnlyStatus' defined in class path resource [ome/services/startup.xml]:
Bean instantiation via constructor failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [ome.services.util.ReadOnlyStatus]: Constructor threw exception; nested exception is ome.conditions.DatabaseBusyException:
Cannot acquire connection

        at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:279) ~[spring-beans.jar:4.3.22.RELEASE]

        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireConstructor(AbstractAutowireCapableBeanFactory.java:1198) ~[spring-beans.jar:4.3.22.RELEASE]

        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1100) ~[spring-beans.jar:4.3.22.RELEASE]

        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:511) ~[spring-beans.jar:4.3.22.RELEASE]

        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:481) ~[spring-beans.jar:4.3.22.RELEASE]

        at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312) ~[spring-beans.jar:4.3.22.RELEASE]

        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230) ~[spring-beans.jar:4.3.22.RELEASE]

        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308) ~[spring-beans.jar:4.3.22.RELEASE]

        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197) ~[spring-beans.jar:4.3.22.RELEASE]

        at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:351) ~[spring-beans.jar:4.3.22.RELEASE]

        ... 49 common frames omitted

Caused by: org.springframework.beans.BeanInstantiationException: Failed to instantiate [ome.services.util.ReadOnlyStatus]: Constructor threw exception; nested exception is ome.conditions.DatabaseBusyException: Cannot acquire connection

        at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:154) ~[spring-beans.jar:4.3.22.RELEASE]

        at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:122) ~[spring-beans.jar:4.3.22.RELEASE]

        at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:271) ~[spring-beans.jar:4.3.22.RELEASE]

        ... 58 common frames omitted

Caused by: ome.conditions.DatabaseBusyException: Cannot acquire connection

        at ome.services.db.SelfCorrectingDataSource.callWithRetries(SelfCorrectingDataSource.java:113) ~[omero-server.jar:5.5.4]

        at ome.services.db.SelfCorrectingDataSource.getConnection(SelfCorrectingDataSource.java:60) ~[omero-server.jar:5.5.4]

        at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111) ~[spring-jdbc.jar:4.3.14.RELEASE]

        at org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy$TransactionAwareInvocationHandler.invoke(TransactionAwareDataSourceProxy.java:225) ~[spring-jdbc.jar:4.3.14.RELEASE]

        at com.sun.proxy.$Proxy7.createStatement(Unknown Source) ~[na:na]

        at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:402) ~[spring-jdbc.jar:4.3.14.RELEASE]

        at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:544) ~[spring-jdbc.jar:4.3.14.RELEASE]

        at ome.util.SqlAction$Impl.deleteCurrentAdminPrivileges(SqlAction.java:744) ~[omero-model.jar:5.5.2]

        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_212]

        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_212]

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_212]

        at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_212]

        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333) ~[spring-aop.jar:4.3.14.RELEASE]

        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190) ~[spring-aop.jar:4.3.14.RELEASE]

        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop.jar:4.3.14.RELEASE]

        at ome.util.SqlAction$LoggingSqlAction.invoke(SqlAction.java:85) ~[omero-model.jar:5.5.2]

        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop.jar:4.3.14.RELEASE]

        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213) ~[spring-aop.jar:4.3.14.RELEASE]

        at com.sun.proxy.$Proxy6.deleteCurrentAdminPrivileges(Unknown Source) ~[na:na]

        at ome.services.util.ReadOnlyStatus.canWriteDb(ReadOnlyStatus.java:50) ~[omero-server.jar:5.5.4]

        at ome.services.util.ReadOnlyStatus.<init>(ReadOnlyStatus.java:43) ~[omero-server.jar:5.5.4]

        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_212]

        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_212]

        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_212]

        at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[na:1.8.0_212]

        at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:142) ~[spring-beans.jar:4.3.22.RELEASE]

        ... 60 common frames omitted

Here is bin/omero admin diagnostics:

[omero@bioimages OMERO.server]$ bin/omero admin diagnostics

joshmoore · July 22, 2019, 6:11am

@fhagemei, it looks like your diagnostics output got cut off, but from the log output, I’d say that the configuration to connect to the database needs checking. These are the properties starting with omero.db.* from

bin/omero config get

For example, did you change the name of your upgraded database?

~Josh

fhagemei · July 22, 2019, 8:42pm

Thanks. Further below is the bin/omero admin diagnostics command output. The command ‘bin/omero config get’ returns 'omero.data.dir=/images" .

Thanks!

[omero@bioimages OMERO.server]$ bin/omero admin diagnostics

================================================================================
OMERO Diagnostics (admin) 5.5.1-ice36-b122
================================================================================
        
Commands:   java -version                  1.8.0     (/usr/bin/java)
Commands:   python -V                      2.7.5     (/usr/bin/python)
Commands:   icegridnode --version          3.6.4     (/usr/bin/icegridnode)
Commands:   icegridadmin --version         3.6.4     (/usr/bin/icegridadmin)
Commands:   psql --version                 9.6.13    (/usr/bin/psql)
Commands:   openssl version                1.0.2     (/usr/bin/openssl)

Server:     icegridnode                    not started

Log dir:    /home/omero/OMERO.server-5.5.1-ice36-b122/var/log exists
Log files:  Blitz-0.log                    145.0 KB      errors=8    warnings=12  
Log files:  DropBox.log                    6.0 KB        errors=8    warnings=4   
Log files:  FileServer.log                 1.0 KB       
Log files:  Indexer-0.log                  182.0 KB      errors=8    warnings=12  
Log files:  MonitorServer.log              1.0 KB       
Log files:  PixelData-0.log                182.0 KB      errors=8    warnings=12  
Log files:  Processor-0.log                59.0 KB       errors=16   warnings=32  
Log files:  Tables-0.log                   64.0 KB       errors=16   warnings=32  
Log files:  TestDropBox.log                n/a
Log files:  master.err                     1.0 MB        errors=4    warnings=8   
Log files:  master.out                     empty
Log files:  Total size                     1.68 MB


Environment:OMERO_HOME=(unset)             
Environment:OMERO_NODE=(unset)             
Environment:OMERO_MASTER=(unset)           
Environment:OMERO_USERDIR=(unset)          
Environment:OMERO_TMPDIR=(unset)           
Environment:PATH=/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/home/omero/.local/bin:/home/omero/bin 
Environment:PYTHONPATH=(unset)             
Environment:ICE_HOME=(unset)               
Environment:LD_LIBRARY_PATH=(unset)        
Environment:DYLD_LIBRARY_PATH=(unset)      

Cannot list deployed applications.
OMERO data dir:'/images'                      Exists? True	Is writable? True
OMERO temp dir:'/home/omero/omero/tmp'        Exists? True	Is writable? True   (Size: 0)

JVM settings: Blitz-${index}                -Xmx7200m -XX:MaxPermSize=1g -XX:+IgnoreUnrecognizedVMOptions
JVM settings: Indexer-${index}              -Xmx4800m -XX:MaxPermSize=1g -XX:+IgnoreUnrecognizedVMOptions
JVM settings: PixelData-${index}            -Xmx7200m -XX:MaxPermSize=1g -XX:+IgnoreUnrecognizedVMOptions
JVM settings: Repository-${index}           -Xmx4800m -XX:MaxPermSize=1g -XX:+IgnoreUnrecognizedVMOptions

joshmoore · July 22, 2019, 8:45pm

Thanks for the info, @fhagemei.

The fact that no omero.db.* properties are listed along with the defaults says to me that your database is accessible via:

psql -h localhost -U omero omero

with the password omero. Is that the case?

~Josh

fhagemei · July 23, 2019, 8:35pm

It’s a different password and it’s not accessible with the -h localhost, but yes, ‘psql -U omero omero’ works.

joshmoore · July 24, 2019, 11:17am

@fhagemei, then that’s likely the problem. Until:

psql -h ${omero.db.host} -U ${omero.db.user} ${omero.db.name}

with the password ${omero.db.pass}, let’s you connect from the server that OMERO is running on, OMERO.server will not be able to start.

This likely needs:

bin/omero config set omero.db.pass REALPASSWORD

This will need configuring in PostgreSQL’s postgresql.conf and/or pg_hba.conf to permit TCP connections from this host by this user to this DB.

For more information, see https://docs.openmicroscopy.org/omero/5.5.1/sysadmins/unix/server-postgresql.html?highlight=pg_hba%20conf

~Josh

fhagemei · July 24, 2019, 11:17am

Setting omero.db.pass did it. So I grepped the password to where it is stored and learned that the command to set it must push it to several config files. So it makes sense that the upgrade needed to set the db password since the app folder was blown away. Looking through the upgrade doc, I guess my SA who did the upgrade must not have realized he needed to set the password. The upgrade doc talks about looking at the password matrix at https://docs.openmicroscopy.org/omero/5.5.1/sysadmins/troubleshooting.html#troubleshooting-password , but since he didn’t change any passwords, he didn’t think anything needed to be set under the Database Accounts section.

Thanks!

joshmoore · July 24, 2019, 11:18am

No problem. Glad to hear it’s working! ~Josh