Closed will-moore closed 2 years ago
Again today as https://www.openmicroscopy.org/qa2/qa/feedback/30414/
setChannel OptimisticLockException: https://www.openmicroscopy.org/qa2/qa/feedback/30965/
File "/opt/omero/venv_web/lib64/python3.6/site-packages/omeroweb/webclient/views.py", line 2803, in edit_channel_names
counts = conn.setChannelNames(ptype, [pid], nameDict, channelCount=sizeC)
File "/opt/omero/venv_web/lib64/python3.6/site-packages/omero/gateway/__init__.py", line 4015, in setChannelNames
self.getUpdateService().saveCollection(toSave, ctx)
File "/opt/omero/venv_web/lib64/python3.6/site-packages/omero/gateway/__init__.py", line 4856, in __call__
return self.handle_exception(e, *args, **kwargs)
File "/opt/omero/venv_web/lib64/python3.6/site-packages/omeroweb/webclient/webclient_gateway.py", line 2109, in handle_exception
super(OmeroWebSafeCallWrapper, self).handle_exception(e, *args, **kwargs)
File "/opt/omero/venv_web/lib64/python3.6/site-packages/omero/gateway/__init__.py", line 4853, in __call__
return self.f(*args, **kwargs)
File "/opt/omero/venv_web/lib64/python3.6/site-packages/omero_api_IUpdate_ice.py", line 154, in saveCollection
return _M_omero.api.IUpdate._op_saveCollection.invoke(self, ((objs, ), _ctx))
omero.OptimisticLockException: exception ::omero::OptimisticLockException
Another reported at https://www.openmicroscopy.org/qa2/qa/feedback/30968/
@will-moore : do you have a feeling for which calls are being made (more or less) concurrently?
Saving a bunch of channels, some of which might be linked in the same graph:
So copying an unlinked version as recently discussed on image.sc with the well samples would be one solution?
Again on nightshade e-mail today 9:48:
TryAgain at /webclient/edit_channel_names/4523073/
exception ::omero::TryAgain
{
serverStackTrace = ome.conditions.TryAgain: Hibernate operation: could not update: [ome.model.core.LogicalChannel#9881976]; SQL [update logicalchannel set contrastMethod=?, external_id=?, group_id=?, owner_id=?, update_id=?, detectorSettings=?, emissionWaveUnit=?, emissionWave=?, excitationWaveUnit=?, excitationWave=?, filterSet=?, fluor=?, illumination=?, lightPath=?, lightSourceSettings=?, "mode"=?, name=?, ndFilter=?, otf=?, photometricInterpretation=?, pinHoleSizeUnit=?, pinHoleSize=?, pockelCellSetting=?, samplesPerPixel=?, version=? where id=?]; ERROR: deadlock detected
https://www.openmicroscopy.org/qa2/qa/feedback/31128/
serverStackTrace = ome.conditions.OptimisticLockException: You are not authorized to change the update event for ome.model.core.LogicalChannel:Id_3413456 from ome.model.meta.Event:Id_59325409 to ome.model.meta.Event:Id_59291893
You may need to reload the object before continuing.
This issue has been mentioned on Image.sc Forum. There might be relevant details there:
https://forum.image.sc/t/apply-channel-names-to-all-images-in-an-omero-dataset-possible-bug/70521/4
This issue has been mentioned on Image.sc Forum. There might be relevant details there:
https://forum.image.sc/t/apply-channel-names-to-all-images-in-an-omero-dataset-possible-bug/70521/7
Below is an excerpt from our omero-web.log. This refers to the problem described in the above mentioned Image.sc post.
2022-08-11 09:22:06,861 INFO [ omero.gateway] (proc.02376) close():1987 closed connection (uuid=345be5b0-d3ce-4211-ab6a-1976ccbfbaee) 2022-08-11 09:22:06,862 ERROR [ omeroweb.feedback.views] (proc.02376) handler500():163 handler500: Server error 2022-08-11 09:22:06,865 ERROR [ omeroweb.feedback.views] (proc.02376) handler500():166 Traceback (most recent call last):
File "/opt/omero/web/venv36/lib/python3.6/site-packages/django/core/handlers/exception.py", line 47, in inner response = get_response(request)
File "/opt/omero/web/venv36/lib/python3.6/site-packages/django/core/handlers/base.py", line 181, in _get_response response = wrapped_callback(request, *callback_args, **callback_kwargs)
File "/opt/omero/web/venv36/lib/python3.6/site-packages/django/views/decorators/http.py", line 40, in inner return func(request, *args, **kwargs)
File "/opt/omero/web/venv36/lib/python3.6/site-packages/omeroweb/decorators.py", line 538, in wrapped retval = f(request, *args, **kwargs)
File "/opt/omero/web/venv36/lib/python3.6/site-packages/omeroweb/decorators.py", line 597, in wrapper context = f(request, *args, **kwargs)
File "/opt/omero/web/venv36/lib/python3.6/site-packages/omeroweb/webclient/views.py", line 2809, in edit_channel_names counts = conn.setChannelNames(ptype, [pid], nameDict, channelCount=sizeC)
File "/opt/omero/web/venv36/lib/python3.6/site-packages/omero/gateway/init.py", line 4017, in setChannelNames self.getUpdateService().saveCollection(toSave, ctx)
File "/opt/omero/web/venv36/lib/python3.6/site-packages/omero/gateway/init.py", line 4858, in call return self.handle_exception(e, *args, **kwargs)
File "/opt/omero/web/venv36/lib/python3.6/site-packages/omeroweb/webclient/webclient_gateway.py", line 2109, in handle_exception super(OmeroWebSafeCallWrapper, self).handle_exception(e, *args, **kwargs)
File "/opt/omero/web/venv36/lib/python3.6/site-packages/omero/gateway/init.py", line 4855, in call return self.f(*args, **kwargs)
File "/opt/omero/web/venv36/lib/python3.6/site-packages/omero_api_IUpdate_ice.py", line 154, in saveCollection return _M_omero.api.IUpdate._op_saveCollection.invoke(self, ((objs, ), _ctx))
omero.TryAgain: exception ::omero::TryAgain { serverStackTrace = ome.conditions.TryAgain: Hibernate operation: could not update: [ome.model.core.LogicalChannel#1654868]; SQL [update logicalchannel set contrastMethod=?, external_id=?, group_id=?, owner_id=?, update_id=?, detectorSettings=?, emissionWaveUnit=?, emissionWave=?, excitationWaveUnit=?, excitationWave=?, filterSet=?, fluor=?, illumination=?, lightPath=?, lightSourceSettings=?, "mode"=?, name=?, ndFilter=?, otf=?, photometricInterpretation=?, pinHoleSizeUnit=?, pinHoleSize=?, pockelCellSetting=?, samplesPerPixel=?, version=? where id=?]; ERROR: deadlock detected Detail: Process 20387 waits for ShareLock on transaction 5257104; blocked by process 20277. Process 20277 waits for ExclusiveLock on tuple (21024,52) of relation 17421 of database 16385; blocked by process 20291. Process 20291 waits for ShareLock on transaction 5257099; blocked by process 20284. Process 20284 waits for ExclusiveLock on tuple (21024,51) of relation 17421 of database 16385; blocked by process 20387. Hint: See server log for query details. Where: while locking tuple (21024,51) in relation "logicalchannel"; nested exception is org.postgresql.util.PSQLException: ERROR: deadlock detected Detail: Process 20387 waits for ShareLock on transaction 5257104; blocked by process 20277. Process 20277 waits for ExclusiveLock on tuple (21024,52) of relation 17421 of database 16385; blocked by process 20291. Process 20291 waits for ShareLock on transaction 5257099; blocked by process 20284. Process 20284 waits for ExclusiveLock on tuple (21024,51) of relation 17421 of database 16385; blocked by process 20387. Hint: See server log for query details. Where: while locking tuple (21024,51) in relation "logicalchannel" at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:263) at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:73) at org.springframework.orm.hibernate3.HibernateAccessor.convertJdbcAccessException(HibernateAccessor.java:428) at org.springframework.orm.hibernate3.HibernateAccessor.convertHibernateAccessException(HibernateAccessor.java:414) at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:125) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:249) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:121) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213) at com.sun.proxy.$Proxy100.saveCollection(Unknown Source) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at ome.security.basic.BasicSecurityWiring.invoke(BasicSecurityWiring.java:93) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at ome.services.blitz.fire.AopContextInitializer.invoke(AopContextInitializer.java:43) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213) at com.sun.proxy.$Proxy100.saveCollection(Unknown Source) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at ome.services.blitz.util.IceMethodInvoker.invoke(IceMethodInvoker.java:172) at ome.services.throttling.Callback.run(Callback.java:56) at ome.services.throttling.InThreadThrottlingStrategy.callInvokerOnRawArgs(InThreadThrottlingStrategy.java:56) at ome.services.blitz.impl.AbstractAmdServant.callInvokerOnRawArgs(AbstractAmdServant.java:140) at ome.services.blitz.impl.UpdateI.saveCollection_async(UpdateI.java:74) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at omero.cmd.CallContext.invoke(CallContext.java:85) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213) at com.sun.proxy.$Proxy101.saveCollection_async(Unknown Source) at omero.api._IUpdateTie.saveCollection_async(_IUpdateTie.java:104) at omero.api._IUpdateDisp._saveCollection(_IUpdateDisp.java:203) at omero.api._IUpdateDisp.dispatch(_IUpdateDisp.java:430) at IceInternal.Incoming.invoke(Incoming.java:221) at Ice.ConnectionI.invokeAll(ConnectionI.java:2536) at Ice.ConnectionI.dispatch(ConnectionI.java:1145) at Ice.ConnectionI.message(ConnectionI.java:1056) at IceInternal.ThreadPool.run(ThreadPool.java:395) at IceInternal.ThreadPool.access$300(ThreadPool.java:12) at IceInternal.ThreadPool$EventHandlerThread.run(ThreadPool.java:832) at java.base/java.lang.Thread.run(Thread.java:829)
serverExceptionClass = ome.conditions.TryAgain
message = Hibernate operation: could not update: [ome.model.core.LogicalChannel#1654868]; SQL [update logicalchannel set contrastMethod=?, external_id=?, group_id=?, owner_id=?, update_id=?, detectorSettings=?, emissionWaveUnit=?, emissionWave=?, excitationWaveUnit=?, excitationWave=?, filterSet=?, fluor=?, illumination=?, lightPath=?, lightSourceSettings=?, "mode"=?, name=?, ndFilter=?, otf=?, photometricInterpretation=?, pinHoleSizeUnit=?, pinHoleSize=?, pockelCellSetting=?, samplesPerPixel=?, version=? where id=?]; ERROR: deadlock detected
Detail: Process 20387 waits for ShareLock on transaction 5257104; blocked by process 20277. Process 20277 waits for ExclusiveLock on tuple (21024,52) of relation 17421 of database 16385; blocked by process 20291. Process 20291 waits for ShareLock on transaction 5257099; blocked by process 20284. Process 20284 waits for ExclusiveLock on tuple (21024,51) of relation 17421 of database 16385; blocked by process 20387. Hint: See server log for query details. Where: while locking tuple (21024,51) in relation "logicalchannel"; nested exception is org.postgresql.util.PSQLException: ERROR: deadlock detected Detail: Process 20387 waits for ShareLock on transaction 5257104; blocked by process 20277. Process 20277 waits for ExclusiveLock on tuple (21024,52) of relation 17421 of database 16385; blocked by process 20291. Process 20291 waits for ShareLock on transaction 5257099; blocked by process 20284. Process 20284 waits for ExclusiveLock on tuple (21024,51) of relation 17421 of database 16385; blocked by process 20387. Hint: See server log for query details. Where: while locking tuple (21024,51) in relation "logicalchannel" backOff = 500 }
And this is what happened in the Blitz.log at roughly the same time:
2022-08-11 10:22:06,666 WARN [ ome.services.util.ServiceHandler] (.Server-14) Deadlock exception thrown. 2022-08-11 10:22:06,667 WARN [ ome.services.util.ServiceHandler] (.Server-31) Deadlock exception thrown. 2022-08-11 10:22:06,667 INFO [ ome.services.util.ServiceHandler] (.Server-31) Excp: org.springframework.dao.DeadlockLoserDataAccessException: Hibernate operation: could not update: [ome.model.core.LogicalChannel#1654866]; SQL [update logicalchannel set contrastMethod=?, external_id=?, group_id=?, owner_id=?, update_id=?, detectorSettings=?, emissionWaveUnit=?, emissionWave=?, excitationWaveUnit=?, excitationWave=?, filterSet=?, fluor=?, illumination=?, lightPath=?, lightSourceSettings=?, "mode"=?, name=?, ndFilter=?, otf=?, photometricInterpretation=?, pinHoleSizeUnit=?, pinHoleSize=?, pockelCellSetting=?, samplesPerPixel=?, version=? where id=?]; ERROR: deadlock detected 2022-08-11 10:22:06,667 INFO [ ome.services.util.ServiceHandler] (.Server-14) Excp: org.springframework.dao.DeadlockLoserDataAccessException: Hibernate operation: could not update: [ome.model.core.LogicalChannel#1654868]; SQL [update logicalchannel set contrastMethod=?, external_id=?, group_id=?, owner_id=?, update_id=?, detectorSettings=?, emissionWaveUnit=?, emissionWave=?, excitationWaveUnit=?, excitationWave=?, filterSet=?, fluor=?, illumination=?, lightPath=?, lightSourceSettings=?, "mode"=?, name=?, ndFilter=?, otf=?, photometricInterpretation=?, pinHoleSizeUnit=?, pinHoleSize=?, pockelCellSetting=?, samplesPerPixel=?, version=? where id=?]; ERROR: deadlock detected 2022-08-11 10:22:06,673 INFO [ org.perf4j.TimingLogger] (.Server-21) start[1660206122908] time[3764] tag[omero.call.success.ome.logic.UpdateImpl.saveCollection] 2022-08-11 10:22:06,673 INFO [ ome.services.util.ServiceHandler] (.Server-21) Rslt: null 2022-08-11 10:22:06,673 INFO [ ome.security.basic.CurrentDetails] (.Server-33) Adding log:UPDATE,class ome.model.core.LogicalChannel,1654866 2022-08-11 10:22:06,674 INFO [ ome.security.basic.CurrentDetails] (.Server-33) Adding log:UPDATE,class ome.model.core.LogicalChannel,1654868 2022-08-11 10:22:06,674 INFO [o.services.sessions.SessionContext$Count] (.Server-32) -Reference count: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee=4 2022-08-11 10:22:06,675 INFO [ omero.cmd.SessionI] (.Server-32) cleanupSelf(ServiceFactoryI(session-d3f95c43-a5a0-4baa-b8f9-7b43072da5fb/345be5b0-d3ce-4211-ab6a-1976ccbfbaee)). 2022-08-11 10:22:06,675 INFO [ omero.cmd.SessionI] (.Server-32) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/d3f95c43-a5a0-4baa-b8f9-7b43072da5fbomero.api.IQuery(omero.api._IQueryTie@e172de33) 2022-08-11 10:22:06,675 INFO [ omero.cmd.SessionI] (.Server-32) Removed servant from adapter: d3f95c43-a5a0-4baa-b8f9-7b43072da5fbomero.api.IQuery 2022-08-11 10:22:06,675 INFO [ omero.cmd.SessionI] (.Server-32) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/d3f95c43-a5a0-4baa-b8f9-7b43072da5fbomero.api.IUpdate(omero.api._IUpdateTie@d80e382d) 2022-08-11 10:22:06,675 INFO [ omero.cmd.SessionI] (.Server-32) Removed servant from adapter: d3f95c43-a5a0-4baa-b8f9-7b43072da5fbomero.api.IUpdate 2022-08-11 10:22:06,675 INFO [ omero.cmd.SessionI] (.Server-32) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/d3f95c43-a5a0-4baa-b8f9-7b43072da5fbomero.api.IContainer(omero.api._IContainerTie@8fa7c9fc) 2022-08-11 10:22:06,675 INFO [ omero.cmd.SessionI] (.Server-32) Removed servant from adapter: d3f95c43-a5a0-4baa-b8f9-7b43072da5fbomero.api.IContainer 2022-08-11 10:22:06,683 INFO [ org.perf4j.TimingLogger] (.Server-33) start[1660206122896] time[3786] tag[omero.call.success.ome.logic.UpdateImpl.saveCollection] 2022-08-11 10:22:06,683 INFO [ ome.services.util.ServiceHandler] (.Server-33) Rslt: null 2022-08-11 10:22:06,683 INFO [ ome.security.basic.CurrentDetails] (.Server-24) Adding log:UPDATE,class ome.model.core.LogicalChannel,1654866 2022-08-11 10:22:06,684 INFO [ ome.security.basic.CurrentDetails] (.Server-24) Adding log:UPDATE,class ome.model.core.LogicalChannel,1654868 2022-08-11 10:22:06,685 INFO [o.services.sessions.SessionContext$Count] (.Server-26) -Reference count: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee=3 2022-08-11 10:22:06,685 INFO [ omero.cmd.SessionI] (.Server-26) cleanupSelf(ServiceFactoryI(session-5971f511-ae2c-4da6-bc6e-bdbe15ed4e2a/345be5b0-d3ce-4211-ab6a-1976ccbfbaee)). 2022-08-11 10:22:06,685 INFO [ omero.cmd.SessionI] (.Server-26) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/5971f511-ae2c-4da6-bc6e-bdbe15ed4e2aomero.api.IQuery(omero.api._IQueryTie@a1653f7e) 2022-08-11 10:22:06,685 INFO [ omero.cmd.SessionI] (.Server-26) Removed servant from adapter: 5971f511-ae2c-4da6-bc6e-bdbe15ed4e2aomero.api.IQuery 2022-08-11 10:22:06,685 INFO [ omero.cmd.SessionI] (.Server-26) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/5971f511-ae2c-4da6-bc6e-bdbe15ed4e2aomero.api.IUpdate(omero.api._IUpdateTie@e85a3e72) 2022-08-11 10:22:06,685 INFO [ omero.cmd.SessionI] (.Server-26) Removed servant from adapter: 5971f511-ae2c-4da6-bc6e-bdbe15ed4e2aomero.api.IUpdate 2022-08-11 10:22:06,685 INFO [ omero.cmd.SessionI] (.Server-26) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/5971f511-ae2c-4da6-bc6e-bdbe15ed4e2aomero.api.IContainer(omero.api._IContainerTie@b097333f) 2022-08-11 10:22:06,685 INFO [ omero.cmd.SessionI] (.Server-26) Removed servant from adapter: 5971f511-ae2c-4da6-bc6e-bdbe15ed4e2aomero.api.IContainer 2022-08-11 10:22:06,691 INFO [ org.perf4j.TimingLogger] (.Server-24) start[1660206122916] time[3775] tag[omero.call.success.ome.logic.UpdateImpl.saveCollection] 2022-08-11 10:22:06,691 INFO [ ome.services.util.ServiceHandler] (.Server-24) Rslt: null 2022-08-11 10:22:06,693 INFO [o.services.sessions.SessionContext$Count] (.Server-27) -Reference count: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee=2 2022-08-11 10:22:06,693 INFO [ omero.cmd.SessionI] (.Server-27) cleanupSelf(ServiceFactoryI(session-b1945d78-8ca2-4fdf-8a9b-9f7f3b17d71c/345be5b0-d3ce-4211-ab6a-1976ccbfbaee)). 2022-08-11 10:22:06,693 INFO [ omero.cmd.SessionI] (.Server-27) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/b1945d78-8ca2-4fdf-8a9b-9f7f3b17d71comero.api.IUpdate(omero.api._IUpdateTie@d9e70b1b) 2022-08-11 10:22:06,693 INFO [ omero.cmd.SessionI] (.Server-27) Removed servant from adapter: b1945d78-8ca2-4fdf-8a9b-9f7f3b17d71comero.api.IUpdate 2022-08-11 10:22:06,693 INFO [ omero.cmd.SessionI] (.Server-27) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/b1945d78-8ca2-4fdf-8a9b-9f7f3b17d71comero.api.IContainer(omero.api._IContainerTie@b4854cfa) 2022-08-11 10:22:06,693 INFO [ omero.cmd.SessionI] (.Server-27) Removed servant from adapter: b1945d78-8ca2-4fdf-8a9b-9f7f3b17d71comero.api.IContainer 2022-08-11 10:22:06,693 INFO [ omero.cmd.SessionI] (.Server-27) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/b1945d78-8ca2-4fdf-8a9b-9f7f3b17d71comero.api.IQuery(omero.api._IQueryTie@ea47b64f) 2022-08-11 10:22:06,693 INFO [ omero.cmd.SessionI] (.Server-27) Removed servant from adapter: b1945d78-8ca2-4fdf-8a9b-9f7f3b17d71comero.api.IQuery 2022-08-11 10:22:06,763 INFO [o.services.sessions.SessionContext$Count] (.Server-30) -Reference count: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee=1 2022-08-11 10:22:06,764 INFO [ omero.cmd.SessionI] (.Server-30) cleanupSelf(ServiceFactoryI(session-4b7b4c71-bd48-4efb-a656-0502cd5c719c/345be5b0-d3ce-4211-ab6a-1976ccbfbaee)). 2022-08-11 10:22:06,764 INFO [ omero.cmd.SessionI] (.Server-30) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/4b7b4c71-bd48-4efb-a656-0502cd5c719comero.api.IContainer(omero.api._IContainerTie@92b0ae47) 2022-08-11 10:22:06,764 INFO [ omero.cmd.SessionI] (.Server-30) Removed servant from adapter: 4b7b4c71-bd48-4efb-a656-0502cd5c719comero.api.IContainer 2022-08-11 10:22:06,764 INFO [ omero.cmd.SessionI] (.Server-30) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/4b7b4c71-bd48-4efb-a656-0502cd5c719comero.api.IUpdate(omero.api._IUpdateTie@9503e316) 2022-08-11 10:22:06,764 INFO [ omero.cmd.SessionI] (.Server-30) Removed servant from adapter: 4b7b4c71-bd48-4efb-a656-0502cd5c719comero.api.IUpdate 2022-08-11 10:22:06,764 INFO [ omero.cmd.SessionI] (.Server-30) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/4b7b4c71-bd48-4efb-a656-0502cd5c719comero.api.IQuery(omero.api._IQueryTie@ed8285cf) 2022-08-11 10:22:06,764 INFO [ omero.cmd.SessionI] (.Server-30) Removed servant from adapter: 4b7b4c71-bd48-4efb-a656-0502cd5c719comero.api.IQuery 2022-08-11 10:22:06,817 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-29) Found session locally: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:06,818 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-29) Rejoining session ServiceFactoryI(session-b2eaa71c-8762-4461-ba03-f00c26d73b39/345be5b0-d3ce-4211-ab6a-1976ccbfbaee) (agent=OMERO.web) 2022-08-11 10:22:06,855 INFO [o.services.sessions.SessionContext$Count] (.Server-21) -Reference count: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee=1 2022-08-11 10:22:06,856 INFO [ omero.cmd.SessionI] (.Server-21) cleanupSelf(ServiceFactoryI(session-ee295243-6a2b-41d1-b3cd-fc6ef6db962f/345be5b0-d3ce-4211-ab6a-1976ccbfbaee)). 2022-08-11 10:22:06,856 INFO [ omero.cmd.SessionI] (.Server-21) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/ee295243-6a2b-41d1-b3cd-fc6ef6db962fomero.api.IQuery(omero.api._IQueryTie@dc4c64df) 2022-08-11 10:22:06,856 INFO [ omero.cmd.SessionI] (.Server-21) Removed servant from adapter: ee295243-6a2b-41d1-b3cd-fc6ef6db962fomero.api.IQuery 2022-08-11 10:22:06,856 INFO [ omero.cmd.SessionI] (.Server-21) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/ee295243-6a2b-41d1-b3cd-fc6ef6db962fomero.api.IUpdate(omero.api._IUpdateTie@e6f04c7a) 2022-08-11 10:22:06,856 INFO [ omero.cmd.SessionI] (.Server-21) Removed servant from adapter: ee295243-6a2b-41d1-b3cd-fc6ef6db962fomero.api.IUpdate 2022-08-11 10:22:06,856 INFO [ omero.cmd.SessionI] (.Server-21) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/ee295243-6a2b-41d1-b3cd-fc6ef6db962fomero.api.IContainer(omero.api._IContainerTie@a25bdbcb) 2022-08-11 10:22:06,856 INFO [ omero.cmd.SessionI] (.Server-21) Removed servant from adapter: ee295243-6a2b-41d1-b3cd-fc6ef6db962fomero.api.IContainer 2022-08-11 10:22:06,858 INFO [o.services.sessions.SessionContext$Count] (.Server-32) -Reference count: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee=0 2022-08-11 10:22:06,858 INFO [ omero.cmd.SessionI] (.Server-32) cleanupSelf(ServiceFactoryI(session-b2eaa71c-8762-4461-ba03-f00c26d73b39/345be5b0-d3ce-4211-ab6a-1976ccbfbaee)). 2022-08-11 10:22:06,910 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-24) Found session locally: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:06,910 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-27) Found session locally: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:06,911 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-24) Rejoining session ServiceFactoryI(session-d2d905d8-ab13-427c-94e7-f9834f77aa95/345be5b0-d3ce-4211-ab6a-1976ccbfbaee) (agent=OMERO.web) 2022-08-11 10:22:06,911 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-27) Rejoining session ServiceFactoryI(session-30618dd3-99a9-481f-8fe4-8daf97b36cef/345be5b0-d3ce-4211-ab6a-1976ccbfbaee) (agent=OMERO.web) 2022-08-11 10:22:06,918 INFO [ ome.services.util.ServiceHandler] (.Server-14) Executor.doWork -- ome.services.blitz.impl.ServiceFactoryI.isGuest[] 2022-08-11 10:22:06,918 INFO [ ome.services.util.ServiceHandler] (.Server-14) Args: [null, InternalSF@561691849] 2022-08-11 10:22:06,919 INFO [ ome.services.util.ServiceHandler] (.Server-21) Executor.doWork -- ome.services.blitz.impl.ServiceFactoryI.isGuest[] 2022-08-11 10:22:06,919 INFO [ ome.services.util.ServiceHandler] (.Server-21) Args: [null, InternalSF@561691849] 2022-08-11 10:22:06,921 INFO [ ome.security.basic.EventHandler] (.Server-14) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:06,922 INFO [ org.perf4j.TimingLogger] (.Server-14) start[1660206126918] time[4] tag[omero.call.success.ome.services.blitz.impl.ServiceFactoryI$3.doWork] 2022-08-11 10:22:06,923 INFO [ ome.services.util.ServiceHandler] (.Server-14) Rslt: false 2022-08-11 10:22:06,923 INFO [ omero.cmd.SessionI] (.Server-14) Added servant to adapter: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee/30618dd3-99a9-481f-8fe4-8daf97b36cefomero.api.IQuery(omero.api._IQueryTie@a5a6f819) 2022-08-11 10:22:06,925 INFO [ ome.services.util.ServiceHandler] (.Server-33) Meth: interface ome.api.IQuery.findByQuery 2022-08-11 10:22:06,925 INFO [ ome.services.util.ServiceHandler] (.Server-33) Args: [select obj from Image obj join fetch obj.details.owner as owner join fetch obj.details.creationEvent, PARAMS:ids=ArrayList(1) ] 2022-08-11 10:22:06,925 INFO [ ome.security.basic.EventHandler] (.Server-21) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:06,926 INFO [ ome.security.basic.BasicEventContext] (.Server-33) cctx: group=-1 2022-08-11 10:22:06,926 INFO [ org.perf4j.TimingLogger] (.Server-21) start[1660206126919] time[7] tag[omero.call.success.ome.services.blitz.impl.ServiceFactoryI$3.doWork] 2022-08-11 10:22:06,926 INFO [ ome.services.util.ServiceHandler] (.Server-21) Rslt: false 2022-08-11 10:22:06,927 INFO [ omero.cmd.SessionI] (.Server-21) Added servant to adapter: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee/d2d905d8-ab13-427c-94e7-f9834f77aa95omero.api.IQuery(omero.api._IQueryTie@d3f5a677) 2022-08-11 10:22:06,929 INFO [ ome.services.util.ServiceHandler] (.Server-32) Meth: interface ome.api.IQuery.findAllByQuery 2022-08-11 10:22:06,929 INFO [ ome.services.util.ServiceHandler] (.Server-32) Args: [ 2022-08-11 10:22:06,929 INFO [ ome.security.basic.BasicEventContext] (.Server-32) cctx: group=-1 2022-08-11 10:22:06,936 INFO [ ome.security.basic.EventHandler] (.Server-33) Auth: user=102,group=-1,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:06,944 INFO [ ome.security.basic.EventHandler] (.Server-32) Auth: user=102,group=-1,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:06,945 INFO [ org.perf4j.TimingLogger] (.Server-33) start[1660206126925] time[19] tag[omero.call.success.ome.logic.QueryImpl.findByQuery] 2022-08-11 10:22:06,945 INFO [ ome.services.util.ServiceHandler] (.Server-33) Rslt: ome.model.core.Image:Id_1344307 2022-08-11 10:22:06,947 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-24) Found session locally: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:06,948 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-24) Rejoining session ServiceFactoryI(session-f35adab6-7e8c-410a-adb4-053c784560b2/345be5b0-d3ce-4211-ab6a-1976ccbfbaee) (agent=OMERO.web) 2022-08-11 10:22:06,953 INFO [ ome.services.util.ServiceHandler] (.Server-28) Executor.doWork -- ome.services.blitz.impl.ServiceFactoryI.isGuest[] 2022-08-11 10:22:06,954 INFO [ ome.services.util.ServiceHandler] (.Server-28) Args: [null, InternalSF@561691849] 2022-08-11 10:22:06,956 INFO [ ome.security.basic.EventHandler] (.Server-28) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:06,958 INFO [ org.perf4j.TimingLogger] (.Server-28) start[1660206126954] time[3] tag[omero.call.success.ome.services.blitz.impl.ServiceFactoryI$3.doWork] 2022-08-11 10:22:06,958 INFO [ ome.services.util.ServiceHandler] (.Server-28) Rslt: false 2022-08-11 10:22:06,958 INFO [ omero.cmd.SessionI] (.Server-28) Added servant to adapter: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee/f35adab6-7e8c-410a-adb4-053c784560b2omero.api.IQuery(omero.api._IQueryTie@c03908c6) 2022-08-11 10:22:06,959 INFO [ ome.services.util.ServiceHandler] (.Server-29) Meth: interface ome.api.IQuery.findAllByQuery 2022-08-11 10:22:06,959 INFO [ ome.services.util.ServiceHandler] (.Server-29) Args: [select p from Image i join i.datasetLinks dl join dl.parent ds join ds.projectLinks pl join pl.paren, null] 2022-08-11 10:22:06,960 INFO [ ome.security.basic.BasicEventContext] (.Server-29) cctx: group=-1 2022-08-11 10:22:06,960 INFO [ ome.services.util.ServiceHandler] (.Server-31) Meth: interface ome.api.IQuery.findByQuery 2022-08-11 10:22:06,961 INFO [ ome.services.util.ServiceHandler] (.Server-31) Args: [select obj from Image obj join fetch obj.details.owner as owner join fetch obj.details.creationEvent, PARAMS:ids=ArrayList(1) ] 2022-08-11 10:22:06,961 INFO [ ome.security.basic.BasicEventContext] (.Server-31) cctx: group=-1 2022-08-11 10:22:06,968 INFO [ ome.security.basic.EventHandler] (.Server-29) Auth: user=102,group=-1,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:06,970 INFO [ ome.security.basic.EventHandler] (.Server-31) Auth: user=102,group=-1,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:06,978 INFO [ org.perf4j.TimingLogger] (.Server-31) start[1660206126961] time[17] tag[omero.call.success.ome.logic.QueryImpl.findByQuery] 2022-08-11 10:22:06,978 INFO [ ome.services.util.ServiceHandler] (.Server-31) Rslt: ome.model.core.Image:Id_1344307 2022-08-11 10:22:06,981 INFO [ org.perf4j.TimingLogger] (.Server-29) start[1660206126959] time[22] tag[omero.call.success.ome.logic.QueryImpl.findAllByQuery] 2022-08-11 10:22:06,981 INFO [ ome.services.util.ServiceHandler] (.Server-29) Rslt: (ome.model.containers.Project:Id_2951) 2022-08-11 10:22:06,982 INFO [ org.perf4j.TimingLogger] (.Server-32) start[1660206126929] time[52] tag[omero.call.success.ome.logic.QueryImpl.findAllByQuery] 2022-08-11 10:22:06,982 INFO [ ome.services.util.ServiceHandler] (.Server-32) Rslt: () 2022-08-11 10:22:06,983 INFO [o.services.sessions.SessionContext$Count] (.Server-14) -Reference count: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee=2 2022-08-11 10:22:06,983 INFO [ omero.cmd.SessionI] (.Server-14) cleanupSelf(ServiceFactoryI(session-d2d905d8-ab13-427c-94e7-f9834f77aa95/345be5b0-d3ce-4211-ab6a-1976ccbfbaee)). 2022-08-11 10:22:06,983 INFO [ omero.cmd.SessionI] (.Server-14) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/d2d905d8-ab13-427c-94e7-f9834f77aa95omero.api.IQuery(omero.api._IQueryTie@d3f5a677) 2022-08-11 10:22:06,983 INFO [ omero.cmd.SessionI] (.Server-14) Removed servant from adapter: d2d905d8-ab13-427c-94e7-f9834f77aa95omero.api.IQuery 2022-08-11 10:22:06,990 INFO [ ome.services.util.ServiceHandler] (.Server-21) Meth: interface ome.api.IQuery.projection 2022-08-11 10:22:06,990 INFO [ ome.services.util.ServiceHandler] (.Server-21) Args: [select ofile.path, ofile.name, fse.clientPath from FilesetEntry as fse join fse.fileset as fileset j, PARAMS:id=1344307 ] 2022-08-11 10:22:06,991 INFO [ ome.security.basic.BasicEventContext] (.Server-21) cctx: group=-1 2022-08-11 10:22:06,998 INFO [ ome.services.util.ServiceHandler] (.Server-26) Meth: interface ome.api.IQuery.findAllByQuery 2022-08-11 10:22:06,998 INFO [ ome.services.util.ServiceHandler] (.Server-26) Args: [from DatasetImageLink as c where c.child.id=1344307, PARAMS] 2022-08-11 10:22:06,999 INFO [ ome.security.basic.BasicEventContext] (.Server-26) cctx: group=-1 2022-08-11 10:22:07,005 INFO [ ome.security.basic.EventHandler] (.Server-26) Auth: user=102,group=-1,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,006 INFO [ ome.security.basic.EventHandler] (.Server-21) Auth: user=102,group=-1,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,009 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-24) Found session locally: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,010 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-24) Rejoining session ServiceFactoryI(session-e7c23e99-4282-455d-89f1-6daaa5e1bd44/345be5b0-d3ce-4211-ab6a-1976ccbfbaee) (agent=OMERO.web) 2022-08-11 10:22:07,012 INFO [ org.perf4j.TimingLogger] (.Server-26) start[1660206126998] time[13] tag[omero.call.success.ome.logic.QueryImpl.findAllByQuery] 2022-08-11 10:22:07,012 INFO [ ome.services.util.ServiceHandler] (.Server-26) Rslt: (ome.model.containers.DatasetImageLink:Id_1350978) 2022-08-11 10:22:07,016 INFO [ ome.services.util.ServiceHandler] (.Server-28) Executor.doWork -- ome.services.blitz.impl.ServiceFactoryI.isGuest[] 2022-08-11 10:22:07,016 INFO [ ome.services.util.ServiceHandler] (.Server-28) Args: [null, InternalSF@561691849] 2022-08-11 10:22:07,018 INFO [ ome.security.basic.EventHandler] (.Server-28) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,019 INFO [ org.perf4j.TimingLogger] (.Server-28) start[1660206127016] time[3] tag[omero.call.success.ome.services.blitz.impl.ServiceFactoryI$3.doWork] 2022-08-11 10:22:07,019 INFO [ ome.services.util.ServiceHandler] (.Server-28) Rslt: false 2022-08-11 10:22:07,020 INFO [ omero.cmd.SessionI] (.Server-28) Added servant to adapter: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee/e7c23e99-4282-455d-89f1-6daaa5e1bd44omero.api.IQuery(omero.api._IQueryTie@a1c9b005) 2022-08-11 10:22:07,022 INFO [ ome.services.util.ServiceHandler] (.Server-31) Meth: interface ome.api.IQuery.findAllByQuery 2022-08-11 10:22:07,022 INFO [ ome.services.util.ServiceHandler] (.Server-31) Args: [ 2022-08-11 10:22:07,022 INFO [ org.perf4j.TimingLogger] (.Server-21) start[1660206126990] time[31] tag[omero.call.success.ome.logic.QueryImpl.projection] 2022-08-11 10:22:07,022 INFO [ ome.services.util.ServiceHandler] (.Server-21) Rslt: ([Imaging Facility_3/kzentis_102/2022-08/10/13-07-03.635/, composite.ome.tif, home/kzentis/composite.ome.tif]) 2022-08-11 10:22:07,023 INFO [ ome.security.basic.BasicEventContext] (.Server-31) cctx: group=-1 2022-08-11 10:22:07,023 INFO [ ome.services.util.ServiceHandler] (.Server-32) Meth: interface ome.api.IQuery.get 2022-08-11 10:22:07,023 INFO [ ome.services.util.ServiceHandler] (.Server-32) Args: [class ome.model.containers.Dataset, 8904] 2022-08-11 10:22:07,024 INFO [o.services.sessions.SessionContext$Count] (.Server-29) -Reference count: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee=2 2022-08-11 10:22:07,024 INFO [ omero.cmd.SessionI] (.Server-29) cleanupSelf(ServiceFactoryI(session-f35adab6-7e8c-410a-adb4-053c784560b2/345be5b0-d3ce-4211-ab6a-1976ccbfbaee)). 2022-08-11 10:22:07,024 INFO [ omero.cmd.SessionI] (.Server-29) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/f35adab6-7e8c-410a-adb4-053c784560b2omero.api.IQuery(omero.api._IQueryTie@c03908c6) 2022-08-11 10:22:07,024 INFO [ ome.security.basic.BasicEventContext] (.Server-32) cctx: group=-1 2022-08-11 10:22:07,024 INFO [ omero.cmd.SessionI] (.Server-29) Removed servant from adapter: f35adab6-7e8c-410a-adb4-053c784560b2omero.api.IQuery 2022-08-11 10:22:07,031 INFO [ ome.security.basic.EventHandler] (.Server-31) Auth: user=102,group=-1,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,032 INFO [ ome.security.basic.EventHandler] (.Server-32) Auth: user=102,group=-1,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,034 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-33) Found session locally: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,035 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-33) Rejoining session ServiceFactoryI(session-c69e11ed-1598-4ade-8892-8accce3e75da/345be5b0-d3ce-4211-ab6a-1976ccbfbaee) (agent=OMERO.web) 2022-08-11 10:22:07,035 INFO [ org.perf4j.TimingLogger] (.Server-32) start[1660206127023] time[11] tag[omero.call.success.ome.logic.QueryImpl.get] 2022-08-11 10:22:07,035 INFO [ ome.services.util.ServiceHandler] (.Server-32) Rslt: ome.model.containers.Dataset:Id_8904 2022-08-11 10:22:07,040 INFO [ ome.services.util.ServiceHandler] (.Server-27) Executor.doWork -- ome.services.blitz.impl.ServiceFactoryI.isGuest[] 2022-08-11 10:22:07,040 INFO [ ome.services.util.ServiceHandler] (.Server-27) Args: [null, InternalSF@561691849] 2022-08-11 10:22:07,043 INFO [ ome.security.basic.EventHandler] (.Server-27) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,043 INFO [ org.perf4j.TimingLogger] (.Server-27) start[1660206127040] time[3] tag[omero.call.success.ome.services.blitz.impl.ServiceFactoryI$3.doWork] 2022-08-11 10:22:07,043 INFO [ ome.services.util.ServiceHandler] (.Server-27) Rslt: false 2022-08-11 10:22:07,044 INFO [ ome.services.util.ServiceHandler] (.Server-30) Meth: interface ome.api.IQuery.findAllByQuery 2022-08-11 10:22:07,044 INFO [ ome.services.util.ServiceHandler] (.Server-30) Args: [from WellSample as c where c.image.id=1344307, PARAMS] 2022-08-11 10:22:07,044 INFO [ omero.cmd.SessionI] (.Server-27) Added servant to adapter: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee/c69e11ed-1598-4ade-8892-8accce3e75daomero.api.IQuery(omero.api._IQueryTie@db2ffbcc) 2022-08-11 10:22:07,045 INFO [ ome.security.basic.BasicEventContext] (.Server-30) cctx: group=-1 2022-08-11 10:22:07,046 INFO [ ome.services.util.ServiceHandler] (.Server-28) Meth: interface ome.api.IQuery.findByQuery 2022-08-11 10:22:07,046 INFO [ ome.services.util.ServiceHandler] (.Server-28) Args: [select obj from Image obj join fetch obj.details.owner as owner join fetch obj.details.creationEvent, PARAMS:ids=ArrayList(1) ] 2022-08-11 10:22:07,047 INFO [ ome.security.basic.BasicEventContext] (.Server-28) cctx: group=-1 2022-08-11 10:22:07,051 INFO [ org.perf4j.TimingLogger] (.Server-31) start[1660206127022] time[29] tag[omero.call.success.ome.logic.QueryImpl.findAllByQuery] 2022-08-11 10:22:07,052 INFO [ ome.services.util.ServiceHandler] (.Server-31) Rslt: () 2022-08-11 10:22:07,052 INFO [ ome.security.basic.EventHandler] (.Server-30) Auth: user=102,group=-1,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,054 INFO [ ome.security.basic.EventHandler] (.Server-28) Auth: user=102,group=-1,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,055 INFO [o.services.sessions.SessionContext$Count] (.Server-21) -Reference count: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee=2 2022-08-11 10:22:07,055 INFO [ omero.cmd.SessionI] (.Server-21) cleanupSelf(ServiceFactoryI(session-e7c23e99-4282-455d-89f1-6daaa5e1bd44/345be5b0-d3ce-4211-ab6a-1976ccbfbaee)). 2022-08-11 10:22:07,056 INFO [ omero.cmd.SessionI] (.Server-21) Unregistered servant:345be5b0-d3ce-4211-ab6a-1976ccbfbaee/e7c23e99-4282-455d-89f1-6daaa5e1bd44omero.api.IQuery(omero.api._IQueryTie@a1c9b005) 2022-08-11 10:22:07,056 INFO [ omero.cmd.SessionI] (.Server-21) Removed servant from adapter: e7c23e99-4282-455d-89f1-6daaa5e1bd44omero.api.IQuery 2022-08-11 10:22:07,058 INFO [ org.perf4j.TimingLogger] (.Server-30) start[1660206127044] time[13] tag[omero.call.success.ome.logic.QueryImpl.findAllByQuery] 2022-08-11 10:22:07,058 INFO [ ome.services.util.ServiceHandler] (.Server-30) Rslt: () 2022-08-11 10:22:07,059 INFO [ ome.services.util.ServiceHandler] (.Server-29) Meth: interface ome.api.IQuery.findByQuery 2022-08-11 10:22:07,060 INFO [ ome.services.util.ServiceHandler] (.Server-29) Args: [select e from Experimenter e where e.id = 102, null] 2022-08-11 10:22:07,060 INFO [ ome.security.basic.BasicEventContext] (.Server-29) cctx: group=-1 2022-08-11 10:22:07,062 INFO [ org.perf4j.TimingLogger] (.Server-28) start[1660206127046] time[16] tag[omero.call.success.ome.logic.QueryImpl.findByQuery] 2022-08-11 10:22:07,062 INFO [ ome.services.util.ServiceHandler] (.Server-28) Rslt: ome.model.core.Image:Id_1344307 2022-08-11 10:22:07,068 INFO [ ome.security.basic.EventHandler] (.Server-29) Auth: user=102,group=-1,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,071 INFO [ ome.services.util.ServiceHandler] (.Server-14) Executor.doWork -- ome.services.blitz.impl.ServiceFactoryI.isGuest[] 2022-08-11 10:22:07,071 INFO [ ome.services.util.ServiceHandler] (.Server-14) Args: [null, InternalSF@561691849] 2022-08-11 10:22:07,073 INFO [ org.perf4j.TimingLogger] (.Server-29) start[1660206127060] time[12] tag[omero.call.success.ome.logic.QueryImpl.findByQuery] 2022-08-11 10:22:07,073 INFO [ ome.services.util.ServiceHandler] (.Server-29) Rslt: ome.model.meta.Experimenter:Id_102 2022-08-11 10:22:07,074 INFO [ ome.security.basic.EventHandler] (.Server-14) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,075 INFO [ ome.services.util.ServiceHandler] (.Server-33) Executor.doWork -- ome.services.blitz.impl.ServiceFactoryI.isGuest[] 2022-08-11 10:22:07,075 INFO [ ome.services.util.ServiceHandler] (.Server-33) Args: [null, InternalSF@561691849] 2022-08-11 10:22:07,075 INFO [ org.perf4j.TimingLogger] (.Server-14) start[1660206127071] time[3] tag[omero.call.success.ome.services.blitz.impl.ServiceFactoryI$3.doWork] 2022-08-11 10:22:07,075 INFO [ ome.services.util.ServiceHandler] (.Server-14) Rslt: false 2022-08-11 10:22:07,076 INFO [ omero.cmd.SessionI] (.Server-14) Added servant to adapter: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee/c69e11ed-1598-4ade-8892-8accce3e75daomero.api.IContainer(omero.api._IContainerTie@8c2b1bf3) 2022-08-11 10:22:07,078 INFO [ ome.security.basic.EventHandler] (.Server-33) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,078 INFO [ ome.services.util.ServiceHandler] (.Server-32) Meth: interface ome.api.IContainer.getImages 2022-08-11 10:22:07,078 INFO [ ome.services.util.ServiceHandler] (.Server-32) Args: [class ome.model.core.Image, (1344307), null] 2022-08-11 10:22:07,079 INFO [ org.perf4j.TimingLogger] (.Server-33) start[1660206127075] time[3] tag[omero.call.success.ome.services.blitz.impl.ServiceFactoryI$3.doWork] 2022-08-11 10:22:07,079 INFO [ ome.services.util.ServiceHandler] (.Server-33) Rslt: false 2022-08-11 10:22:07,079 INFO [ ome.security.basic.BasicEventContext] (.Server-32) cctx: group=3 2022-08-11 10:22:07,080 INFO [ omero.cmd.SessionI] (.Server-33) Added servant to adapter: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee/30618dd3-99a9-481f-8fe4-8daf97b36cefomero.api.IContainer(omero.api._IContainerTie@a84c8a36) 2022-08-11 10:22:07,081 INFO [ ome.security.basic.EventHandler] (.Server-32) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,082 INFO [ ome.services.util.ServiceHandler] (.Server-24) Meth: interface ome.api.IContainer.getImages 2022-08-11 10:22:07,082 INFO [ ome.services.util.ServiceHandler] (.Server-24) Args: [class ome.model.core.Image, (1344307), null] 2022-08-11 10:22:07,083 INFO [ ome.security.basic.BasicEventContext] (.Server-24) cctx: group=3 2022-08-11 10:22:07,084 INFO [ ome.security.basic.EventHandler] (.Server-24) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,092 INFO [ org.perf4j.TimingLogger] (.Server-32) start[1660206127078] time[13] tag[omero.call.success.ome.logic.PojosImpl.getImages] 2022-08-11 10:22:07,092 INFO [ ome.services.util.ServiceHandler] (.Server-32) Rslt: (ome.model.core.Image:Id_1344307) 2022-08-11 10:22:07,094 INFO [ org.perf4j.TimingLogger] (.Server-24) start[1660206127082] time[12] tag[omero.call.success.ome.logic.PojosImpl.getImages] 2022-08-11 10:22:07,094 INFO [ ome.services.util.ServiceHandler] (.Server-24) Rslt: (ome.model.core.Image:Id_1344307) 2022-08-11 10:22:07,096 INFO [ ome.services.util.ServiceHandler] (.Server-26) Meth: interface ome.api.IQuery.findByQuery 2022-08-11 10:22:07,096 INFO [ ome.services.util.ServiceHandler] (.Server-26) Args: [select p from Pixels p join fetch p.channels as c join fetch c.logicalChannel as lc where p.id=:pid, PARAMS:pid=1344307 ] 2022-08-11 10:22:07,097 INFO [ ome.security.basic.BasicEventContext] (.Server-26) cctx: group=-1 2022-08-11 10:22:07,099 INFO [ ome.services.util.ServiceHandler] (.Server-27) Executor.doWork -- ome.services.blitz.impl.ServiceFactoryI.isGuest[] 2022-08-11 10:22:07,099 INFO [ ome.services.util.ServiceHandler] (.Server-27) Args: [null, InternalSF@561691849] 2022-08-11 10:22:07,102 INFO [ ome.security.basic.EventHandler] (.Server-27) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,103 INFO [ org.perf4j.TimingLogger] (.Server-27) start[1660206127099] time[3] tag[omero.call.success.ome.services.blitz.impl.ServiceFactoryI$3.doWork] 2022-08-11 10:22:07,103 INFO [ ome.services.util.ServiceHandler] (.Server-27) Rslt: false 2022-08-11 10:22:07,104 INFO [ ome.security.basic.EventHandler] (.Server-26) Auth: user=102,group=-1,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,104 INFO [ ome.services.util.ServiceHandler] (.Server-27) Executor.doWork -- ome.services.blitz.impl.ServiceFactoryI.isGuest[] 2022-08-11 10:22:07,104 INFO [ ome.services.util.ServiceHandler] (.Server-27) Args: [null, InternalSF@561691849] 2022-08-11 10:22:07,107 INFO [ ome.security.basic.EventHandler] (.Server-27) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,107 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-21) Found session locally: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,107 INFO [ org.perf4j.TimingLogger] (.Server-27) start[1660206127104] time[3] tag[omero.call.success.ome.services.blitz.impl.ServiceFactoryI$3.doWork] 2022-08-11 10:22:07,107 INFO [ ome.services.util.ServiceHandler] (.Server-27) Rslt: false 2022-08-11 10:22:07,108 INFO [ omero.cmd.SessionI] (.Server-27) Added servant to adapter: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee/30618dd3-99a9-481f-8fe4-8daf97b36cefomero.api.IRoi(omero.api._IRoiTie@8df79f0a) 2022-08-11 10:22:07,108 INFO [ ome.services.blitz.fire.SessionManagerI] (.Server-21) Rejoining session ServiceFactoryI(session-a3393917-7753-445c-8075-fc5b5e6e2d58/345be5b0-d3ce-4211-ab6a-1976ccbfbaee) (agent=OMERO.web) 2022-08-11 10:22:07,108 INFO [ omero.cmd.SessionI] (.Server-27) Added servant to adapter: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee/e216fe56-430c-4945-9faf-75a09d61f7cbomero.api.RenderingEngine(omero.api._RenderingEngineTie@d39bbe6b) 2022-08-11 10:22:07,115 INFO [o.services.sessions.SessionContext$Count] (.Server-29) -Reference count: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee=2 2022-08-11 10:22:07,115 INFO [ omero.cmd.SessionI] (.Server-29) cleanupSelf(ServiceFactoryI(session-a3393917-7753-445c-8075-fc5b5e6e2d58/345be5b0-d3ce-4211-ab6a-1976ccbfbaee)). 2022-08-11 10:22:07,116 INFO [ org.perf4j.TimingLogger] (.Server-26) start[1660206127096] time[19] tag[omero.call.success.ome.logic.QueryImpl.findByQuery] 2022-08-11 10:22:07,116 INFO [ ome.services.util.ServiceHandler] (.Server-26) Rslt: ome.model.core.Pixels:Id_1344307 2022-08-11 10:22:07,125 INFO [ ome.services.util.ServiceHandler] (.Server-14) Meth: interface omeis.providers.re.RenderingEngine.lookupPixels 2022-08-11 10:22:07,125 INFO [ ome.services.util.ServiceHandler] (.Server-14) Args: [1344307] 2022-08-11 10:22:07,125 INFO [ ome.services.util.ServiceHandler] (.Server-14) Executor.doWork -- ome.services.RenderingBean.retrievePixels[] 2022-08-11 10:22:07,125 INFO [ ome.services.util.ServiceHandler] (.Server-14) Args: [null, InternalSF@561691849] 2022-08-11 10:22:07,126 INFO [ ome.security.basic.BasicEventContext] (.Server-14) cctx: group=3 2022-08-11 10:22:07,128 INFO [ ome.security.basic.EventHandler] (.Server-14) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,134 INFO [ ome.services.util.ServiceHandler] (.Server-33) Meth: interface ome.api.IQuery.findAllByQuery 2022-08-11 10:22:07,134 INFO [ ome.services.util.ServiceHandler] (.Server-33) Args: [select l from ChannelAnnotationLink as l join fetch l.details.owner join fetch l.details.creationEve, null] 2022-08-11 10:22:07,135 INFO [ ome.security.basic.BasicEventContext] (.Server-33) cctx: group=3 2022-08-11 10:22:07,137 INFO [ ome.security.basic.EventHandler] (.Server-33) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,142 INFO [ org.perf4j.TimingLogger] (.Server-14) start[1660206127125] time[16] tag[omero.call.success.ome.services.RenderingBean$4.doWork] 2022-08-11 10:22:07,142 INFO [ ome.services.util.ServiceHandler] (.Server-14) Rslt: ome.model.core.Pixels:Id_1344307 2022-08-11 10:22:07,142 INFO [ org.perf4j.TimingLogger] (.Server-14) start[1660206127125] time[17] tag[omero.call.success.ome.services.RenderingBean.lookupPixels] 2022-08-11 10:22:07,142 INFO [ ome.services.util.ServiceHandler] (.Server-14) Rslt: null 2022-08-11 10:22:07,143 INFO [ ome.services.util.ServiceHandler] (.Server-32) Meth: interface omeis.providers.re.RenderingEngine.lookupRenderingDef 2022-08-11 10:22:07,143 INFO [ ome.services.util.ServiceHandler] (.Server-32) Args: [1344307] 2022-08-11 10:22:07,143 INFO [ ome.services.util.ServiceHandler] (.Server-32) Executor.doWork -- ome.services.RenderingBean.retrieveRndDef[] 2022-08-11 10:22:07,143 INFO [ ome.services.util.ServiceHandler] (.Server-32) Args: [null, InternalSF@561691849] 2022-08-11 10:22:07,145 INFO [ ome.security.basic.BasicEventContext] (.Server-32) cctx: group=3 2022-08-11 10:22:07,147 INFO [ ome.security.basic.EventHandler] (.Server-32) Auth: user=102,group=3,event=null(User),sess=345be5b0-d3ce-4211-ab6a-1976ccbfbaee 2022-08-11 10:22:07,153 INFO [ org.perf4j.TimingLogger] (.Server-33) start[1660206127134] time[19] tag[omero.call.success.ome.logic.QueryImpl.findAllByQuery] 2022-08-11 10:22:07,153 INFO [ ome.services.util.ServiceHandler] (.Server-33) Rslt: () 2022-08-11 10:22:07,155 INFO [o.services.sessions.SessionContext$Count] (.Server-24) -Reference count: 345be5b0-d3ce-4211-ab6a-1976ccbfbaee=1
This issue has been mentioned on Image.sc Forum. There might be relevant details there:
https://forum.image.sc/t/apply-channel-names-to-all-images-in-an-omero-dataset-possible-bug/70521/8
Seen again on nightshade:
Internal Server Error: /webclient/edit_channel_names/4529422/
TryAgain at /webclient/edit_channel_names/4529422/
exception ::omero::TryAgain
{
serverStackTrace = ome.conditions.TryAgain: Hibernate operation: could not update: [ome.model.core.LogicalChannel#9894961]; SQL [update logicalchannel set contrastMethod=?, external_id=?, group_id=?, owner_id=?, update_id=?, detectorSettings=?, emissionWaveUnit=?, emissionWave=?, excitationWaveUnit=?, excitationWave=?, filterSet=?, fluor=?, illumination=?, lightPath=?, lightSourceSettings=?, "mode"=?, name=?, ndFilter=?, otf=?, photometricInterpretation=?, pinHoleSizeUnit=?, pinHoleSize=?, pockelCellSetting=?, samplesPerPixel=?, version=? where id=?]; ERROR: deadlock detected
Detail: Process 10231 waits for ShareLock on transaction 33031253; blocked by process 9958.
Process 9958 waits for ShareLock on transaction 33031252; blocked by process 10231.
Hint: See server log for query details.
Where: while updating tuple (27498,9) in relation "logicalchannel"; nested exception is org.postgresql.util.PSQLException: ERROR: deadlock detected
Detail: Process 10231 waits for ShareLock on transaction 33031253; blocked by process 9958.
Process 9958 waits for ShareLock on transaction 33031252; blocked by process 10231.
Hint: See server log for query details.
Where: while updating tuple (27498,9) in relation "logicalchannel"
at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:263)
at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:73)
at org.springframework.orm.hibernate3.HibernateAccessor.convertJdbcAccessException(HibernateAccessor.java:428)
at org.springframework.orm.hibernate3.HibernateAccessor.convertHibernateAccessException(HibernateAccessor.java:414)
Following the previous exception with could not update: [ome.model.core.LogicalChannel#9894961]
I looked up the image that belongs to...
$ omero hql -q --limit=10 --all "select id, pixels from Channel where logicalChannel=9894961"
# | Col1 | Col2
---+----------+-----------------
0 | 10019402 | PixelsI:4527337
(1 row)
$ omero hql -q --limit=10 --all "select p.image from Pixels p where p.id=4527337"
# | Class | Id | details | series | format | objectiveSettings | instrument | fileset | name
---+--------+---------+-----------------------+--------+------------+---------------------------+--------------------+-----------------+--------------------
0 | ImageI | 4529437 | owner=7556;group=2702 | 0 | FormatI:45 | ObjectiveSettingsI:491287 | InstrumentI:485237 | FilesetI:451584 | ***image_name***.nd2
(1 row)
That Image is different from the Image ID in the URL Internal Server Error: /webclient/edit_channel_names/4529422/
but is in the same Dataset.
this is more likely a "derived" image and they share the logical channel. This is what happens for example when the user does a projection
@jburel But in that case, the hql
queries above would give me more than 1 Pixels or Image, but they only return 1.
Yes sorry, so it means maybe the call is the incorrect ImageID
Ah - the Image ID in the URL Internal Server Error: /webclient/edit_channel_names/4529422/
is simply the Image that was chosen when channels were edited and "Save to All" was clicked. But the save applies to all images in the Dataset, so it's not surprising that the error involves a logical channel from a different image.
But, still not managed to reproduce this error (although we do see failures due to timeouts in web).
From e-mail today:
Also seen this:
OptimisticLockException
(Fri 18/06/2021 01:40):