Exception starting server

Hello,

I’m installing another OMERO.server 5.6.2 instance and I’m running into the exception below.

Any help would be appreciated.

Paul

2020-11-19 10:33:07,944 WARN  [        ome.services.util.ServiceHandler] (      main) Unknown exception thrown.

org.springframework.dao.InvalidDataAccessApiUsageException: Unable to determine the correct call signature - no procedure/function/signature for '_prepare_session'
        at org.springframework.jdbc.core.metadata.GenericCallMetaDataProvider.processProcedureColumns(GenericCallMetaDataProvider.java:347) ~[spring-jdbc.jar:4.3.14.RELEASE]
        at org.springframework.jdbc.core.metadata.GenericCallMetaDataProvider.initializeWithProcedureColumnMetaData(GenericCallMetaDataProvider.java:112) ~[spring-jdbc.jar:4.3.14.
RELEASE]
        at org.springframework.jdbc.core.metadata.CallMetaDataProviderFactory$1.processMetaData(CallMetaDataProviderFactory.java:133) ~[spring-jdbc.jar:4.3.14.RELEASE]
        at org.springframework.jdbc.support.JdbcUtils.extractDatabaseMetaData(JdbcUtils.java:336) ~[spring-jdbc.jar:4.3.14.RELEASE]
        at org.springframework.jdbc.core.metadata.CallMetaDataProviderFactory.createMetaDataProvider(CallMetaDataProviderFactory.java:73) ~[spring-jdbc.jar:4.3.14.RELEASE]
        at org.springframework.jdbc.core.metadata.CallMetaDataContext.initializeMetaData(CallMetaDataContext.java:242) ~[spring-jdbc.jar:4.3.14.RELEASE]
        at org.springframework.jdbc.core.simple.AbstractJdbcCall.compileInternal(AbstractJdbcCall.java:303) ~[spring-jdbc.jar:4.3.14.RELEASE]
        at org.springframework.jdbc.core.simple.AbstractJdbcCall.compile(AbstractJdbcCall.java:288) ~[spring-jdbc.jar:4.3.14.RELEASE]
        at org.springframework.jdbc.core.simple.AbstractJdbcCall.checkCompiled(AbstractJdbcCall.java:348) ~[spring-jdbc.jar:4.3.14.RELEASE]
        at org.springframework.jdbc.core.simple.AbstractJdbcCall.doExecute(AbstractJdbcCall.java:363) ~[spring-jdbc.jar:4.3.14.RELEASE]
        at org.springframework.jdbc.core.simple.SimpleJdbcCall.executeFunction(SimpleJdbcCall.java:165) ~[spring-jdbc.jar:4.3.14.RELEASE]
        at ome.util.actions.PostgresSqlAction.prepareSession(PostgresSqlAction.java:82) ~[omero-model.jar:5.6.1]
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na]
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
        at java.base/java.lang.reflect.Method.invoke(Method.java:566) ~[na:na]
        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.6.1]
        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.$Proxy7.prepareSession(Unknown Source) ~[na:na]
        at ome.security.basic.EventHandler.doLogin(EventHandler.java:228) ~[omero-server.jar:5.6.0]
        at ome.security.basic.EventHandler.invoke(EventHandler.java:146) ~[omero-server.jar:5.6.0]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop.jar:4.3.14.RELEASE]
        at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:119) ~[spring-orm.jar:4.3.14.RELEASE]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop.jar:4.3.14.RELEASE]
        at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) ~[spring-tx.jar:4.3.14.RELEASE]
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282) ~[spring-tx.jar:4.3.14.RELEASE]
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx.jar:4.3.14.RELEASE]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop.jar:4.3.14.RELEASE]
        at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:249) ~[omero-server.jar:5.6.0]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop.jar:4.3.14.RELEASE]
        at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:121) ~[omero-server.jar:5.6.0]
        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.$Proxy73.doWork(Unknown Source) ~[na:na]
        at ome.services.util.Executor$Impl.execute(Executor.java:447) ~[omero-server.jar:5.6.0]
        at ome.services.util.EnsureEnum.ensure(EnsureEnum.java:122) ~[omero-server.jar:5.6.0]
        at ome.services.util.DBEnumCheck.doCheck(DBEnumCheck.java:55) ~[omero-server.jar:5.6.0]
        at ome.services.util.BaseDBCheck.start(BaseDBCheck.java:118) ~[omero-server.jar:5.6.0]
        at ome.services.util.DBEnumCheck.start(DBEnumCheck.java:31) ~[omero-server.jar:5.6.0]
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na]
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
        at java.base/java.lang.reflect.Method.invoke(Method.java:566) ~[na:na]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1760) ~[spring-beans.jar:4.3
.22.RELEASE]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1697) ~[spring-beans.jar:4.3.22.R
ELEASE]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1627) ~[spring-beans.jar:4.3.22.RELE
ASE]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553) ~[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.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:761) ~[spring-beans.jar:4.3.22.RELEASE]
        at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:867) ~[spring-context.jar:4.3.14.RELEASE]
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:543) ~[spring-context.jar:4.3.14.RELEASE]
        at org.springframework.context.support.ClassPathXmlApplicationContext.<init>(ClassPathXmlApplicationContext.java:139) ~[spring-context.jar:4.3.14.RELEASE]
        at org.springframework.context.support.ClassPathXmlApplicationContext.<init>(ClassPathXmlApplicationContext.java:105) ~[spring-context.jar:4.3.14.RELEASE]
        at ome.system.OmeroContext.<init>(OmeroContext.java:97) ~[omero-common.jar:5.5.6]
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:na]
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:na]
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:na]
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490) ~[na:na]
        at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:142) ~[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]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireConstructor(AbstractAutowireCapableBeanFactory.java:1198) ~[spring-beans.jar:4.3.22.RELEASE]

Hi @paulkorir,

Sorry for the slow response, this one has me a bit stumped.

Is there any difference between this instance and your currently working one? Which Java version (and which vendor) is on each?

Are there any related messages in master.out or master.err?

All the best,
~Josh

Hi Josh,

Hope you and yours are keeping well.

I’ll try and re-install from scratch and see if that helps. (It might sound like overkill but thing is I’ve already started… )

If not I’ll get back to you.

Regards,

1 Like

Hi Josh,

Here is some (redacted) output in master.err:

-! 11/27/20 12:04:07.896 OMERO.Glacier2: warning: unable to contact permissions verifier `BlitzVerifier@BlitzAdapters'
   Reference.cpp:1637: Ice::NoEndpointException:
   no suitable endpoint available for proxy `BlitzVerifier -t -e 1.1 @ BlitzAdapters'
     0 IceUtil::Exception::Exception(char const*, int) in /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIceUtil.so.36
     1 Ice::LocalException::LocalException(char const*, int) in /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36
     2 Ice::NoEndpointException::NoEndpointException(char const*, int, std::string const&) in /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36
     3 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x30d774) [0x7fdc526d3774]
     4 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x28adef) [0x7fdc52650def]
     5 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x28bb7b) [0x7fdc52651b7b]
     6 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x29c73d) [0x7fdc5266273d]
     7 Ice::AsyncResult::invokeCompleted() in /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36
     8 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x1b18eb) [0x7fdc525778eb]
     9 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x1b10b6) [0x7fdc525770b6]
    10 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x34575e) [0x7fdc5270b75e]
    11 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x347c2a) [0x7fdc5270dc2a]
    12 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIceUtil.so.36(+0x52944) [0x7fdc521a1944]
    13 /lib64/libpthread.so.0(+0x7ea5) [0x7fdc5184bea5]
    14 clone() in /lib64/libc.so.6
-! 11/27/20 12:04:07.898 OMERO.Glacier2: warning: unable to contact session manager `BlitzManager@BlitzAdapters'
   Reference.cpp:1637: Ice::NoEndpointException:
   no suitable endpoint available for proxy `BlitzManager -t -e 1.1 @ BlitzAdapters'

Does this ring a bell?
Thanks,
Paul

That sounds like the C++ components are starting up (icegridnode, glacier2router) but not the Java components (Blitz-0). Can you compare the two Java versions that are being used for me?

I hope I understand what you mean.

Development (working):

openjdk 11.0.8-internal 2020-07-14
OpenJDK Runtime Environment (build 11.0.8-internal+0-adhoc..src)
OpenJDK 64-Bit Server VM (build 11.0.8-internal+0-adhoc..src, mixed mode)

Staging (broken):

openjdk 11.0.8-internal 2020-07-14
OpenJDK Runtime Environment (build 11.0.8-internal+0-adhoc..src)
OpenJDK 64-Bit Server VM (build 11.0.8-internal+0-adhoc..src, mixed mode)

Seem exactly the same to me.

Yup, I agree. Can you stop the staging server, mv var/ out of the way, restart, and send me the server logs (privately if you prefer)?

Doing so right now. It’ll take a minute or two.

How may I contact you privately? :thinking:

Thanks for the file, @paulkorir. Unfortunately, I don’t see anything more than what you’ve shown us here. I’m grasping at straws, but I wonder, for example, if the CLASSPATH environment variable might be set. Otherwise, are the same packages (beyond Java) installed on both servers?

Thanks for your reply.

CLASSPATH is not set on either installation. Here are environment snapshots. stag is the broken installation. dev works.

server-dev.yml (2.9 KB) server-stag.yml (3.1 KB)

Interesting, thanks @paulkorir. Though there are quite a few differences in the two setups, I don’t see anything obvious that would lead to the odd error you’re seeing. Grasping at straws a bit:

  • What’s the uptime on each of the systems? Could a reboot on the staging server help?
  • Is there anything pertinent in the system logs?

~J.

Thank you very much @joshmoore. I’ll request a restart and check the sys logs.

Yes, I’m also completely stumped. I’ve practically checked everything sensible (except the restart and sys logs).

So these lines don’t suggest anything to change? It appears that the Java error comes before the Ice error (timestamps in the logs).

# Blitz-0.log
2020-11-30 10:22:09,989 INFO  [        ome.services.util.ServiceHandler] (      main)  Excp:    org.springframework.dao.InvalidDataAccessApiUsageException: Unable to determine the correct call signature - no procedure/function/signature for '_prepare_session'
2020-11-30 10:22:09,990 WARN  [                 ome.system.OmeroContext] (      main) Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'dbFormatEnumerationCheck' defined in class path resource [ome/services/startup.xml]: Invocation of init method failed; nested exception is ome.conditions.InternalException:  Wrapped Exception: (org.springframework.dao.InvalidDataAccessApiUsageException):
Unable to determine the correct call signature - no procedure/function/signature for '_prepare_session'

**********
# master.err
-! 11/30/20 10:22:10.053 OMERO.Glacier2: warning: unable to contact permissions verifier `BlitzVerifier@BlitzAdapters'
   Reference.cpp:1637: Ice::NoEndpointException:
   no suitable endpoint available for proxy `BlitzVerifier -t -e 1.1 @ BlitzAdapters'
     0 IceUtil::Exception::Exception(char const*, int) in /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIceUtil.so.36
     1 Ice::LocalException::LocalException(char const*, int) in /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36
     2 Ice::NoEndpointException::NoEndpointException(char const*, int, std::string const&) in /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36
     3 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x30d774) [0x7f0db3719774]
     4 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x28adef) [0x7f0db3696def]
     5 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x28bb7b) [0x7f0db3697b7b]
     6 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x29c73d) [0x7f0db36a873d]
     7 Ice::AsyncResult::invokeCompleted() in /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36
     8 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x1b18eb) [0x7f0db35bd8eb]
     9 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x1b10b6) [0x7f0db35bd0b6]
    10 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x34575e) [0x7f0db375175e]
    11 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIce.so.36(+0x347c2a) [0x7f0db3753c2a]
    12 /omero-5.6.2/staging/Ice-3.6.5/bin/../lib64/libIceUtil.so.36(+0x52944) [0x7f0db31e7944]
    13 /lib64/libpthread.so.0(+0x7ea5) [0x7f0db2891ea5]
    14 clone() in /lib64/libc.so.6
-! 11/30/20 10:22:10.056 OMERO.Glacier2: warning: unable to contact session manager `BlitzManager@BlitzAdapters'
   Reference.cpp:1637: Ice::NoEndpointException:
   no suitable endpoint available for proxy `BlitzManager -t -e 1.1 @ BlitzAdapters'

I’ve seen that BlitzVerifier and BlitzManager are defined in etc/grid/templates.xml.

I tried interacting with Ice components:

(omero-server) user@host:/omero-5.6.2/staging/server/OMERO.server $ omero admin ice
Ice 3.6.5  Copyright (c) 2003-2018 ZeroC, Inc.
>>>
>>>
>>> ?
error: syntax error
unknown `?' command (see `help' for more info)
>>> help
help                        Print this message.
exit, quit                  Exit this program.
CATEGORY help               Print the help section of the given CATEGORY.
COMMAND help                Print the help of the given COMMAND.

List of help categories:

  application: commands to manage applications
  node: commands to manage nodes
  registry: commands to manage registries
  server: commands to manage servers
  service: commands to manage services
  adapter: commands to manage adapters
  object: commands to manage objects
  server template: commands to manage server templates
  service template: commands to manage service templates

>>> server
error: syntax error
invalid `server' command (see `server help' for more info)
>>> server help
server list               List all registered servers.
server remove ID          Remove server ID.
server describe ID        Describe server ID.
server properties ID      Get the run-time properties of server ID.
server property ID NAME   Get the run-time property NAME of server ID.
server state ID           Get the state of server ID.
server pid ID             Get the process id of server ID.
server start ID           Start server ID.
server stop ID            Stop server ID.
server patch ID           Patch server ID.
server signal ID SIGNAL   Send SIGNAL (e.g. SIGTERM or 15) to server ID.
server stdout ID MESSAGE  Write MESSAGE on server ID's stdout.
server stderr ID MESSAGE  Write MESSAGE on server ID's stderr.
server show [OPTIONS] ID [log | stderr | stdout | LOGFILE ]
                          Show server ID Ice log, stderr, stdout or log file LOGFILE.
                          Options:
                           -f | --follow: Wait for new data to be available
                           -t N | --tail N: Print the last N log messages or lines
                           -h N | --head N: Print the first N lines (not available for Ice log)
server enable ID          Enable server ID.
server disable ID         Disable server ID (a disabled server can't be
                          started on demand or administratively).
>>> server list
Blitz-0
DropBox
FileServer
Indexer-0
MonitorServer
OMERO.Glacier2
OMERO.IceStorm
PixelData-0
Processor-0
Tables-0
TestDropBox
>>> server start Blitz-0
error: the server didn't start successfully:
The server is disabled.
>>> server enable Blitz-0
>>> server state Blitz-0
inactive (disabled)
>>> server start Blitz-0
error: the server didn't start successfully:
The server is disabled.
>>>

One last question: what does an exit status of 1 mean?

~$ omero admin status
~$ echo $?
1

Hi @paulkorir
I notice you’re using a custom path for Ice:

Did you compile this yourself? Could you show us the environment variables (including PATH, LD_LIBRARY_PATH) seen by OMERO.server when it’s started?

0 means OMERO.server is running, 1 means it isn’t.

After much hassle it became clear that the issue was that the DB was misconfigured. I discovered this by accident when I pointed the installation to another worker DB and it worked flawlessly. I did the reverse (pointed the other installation to this one’s DB) and I got the same errors. Finally, I did a fresh postgresql install and it worked.

Therefore, errors associated with this traceback suggest a misconfigured DB.

1 Like