Bug: NoSuchElementException in log

[jburel]

found in blitz log

 c0:a8:1:4:-59ca51f9:1322692bb73:-7febomero.api.ThumbnailStore=ome.services.blitz.impl.ThumbnailStoreI@b306b3
java.lang.RuntimeException: omero.InternalException
    serverStackTrace = "java.util.NoSuchElementException
                        	at java.util.LinkedList.remove(LinkedList.java:644)
                        	at java.util.LinkedList.removeLast(LinkedList.java:144)
                        	at ome.security.basic.CurrentDetails.logout(CurrentDetails.java:180)
                        	at ome.security.basic.BasicSecurityWiring.logout(BasicSecurityWiring.java:110)
                        	at ome.security.basic.BasicSecurityWiring.invoke(BasicSecurityWiring.java:85)
                        	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
                        	at ome.services.blitz.fire.AopContextInitializer.invoke(AopContextInitializer.java:43)
                        	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
                        	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
                        	at $Proxy83.close(Unknown Source)
                        	at ome.services.blitz.impl.AbstractAmdServant.close_async(AbstractAmdServant.java:227)
                        	at ome.services.blitz.impl.AbstractAmdServant.close(AbstractAmdServant.java:198)
                        	at ome.services.blitz.impl.ServiceFactoryI.doDestroy(ServiceFactoryI.java:790)
                        	at ome.services.blitz.impl.ServiceFactoryI.destroy(ServiceFactoryI.java:703)
                        	at Glacier2._SessionDisp.___destroy(_SessionDisp.java:82)
                        	at omero.api._ServiceFactoryDisp.__dispatch(_ServiceFactoryDisp.java:1263)
                        	at IceInternal.Incoming.invoke(Incoming.java:159)
                        	at Ice.ConnectionI.invokeAll(ConnectionI.java:2037)
                        	at Ice.ConnectionI.message(ConnectionI.java:972)
                        	at IceInternal.ThreadPool.run(ThreadPool.java:577)
                        	at IceInternal.ThreadPool.access$100(ThreadPool.java:12)
                        	at IceInternal.ThreadPool$EventHandlerThread.run(ThreadPool.java:971)
                        "
    serverExceptionClass = "java.util.NoSuchElementException"
    message = (null)
	at ome.services.blitz.impl.AbstractAmdServant$1.ice_exception(AbstractAmdServant.java:191)
	at ome.services.blitz.impl.AbstractAmdServant.close_async(AbstractAmdServant.java:255)
	at ome.services.blitz.impl.AbstractAmdServant.close(AbstractAmdServant.java:198)
	at ome.services.blitz.impl.ServiceFactoryI.doDestroy(ServiceFactoryI.java:790)
	at ome.services.blitz.impl.ServiceFactoryI.destroy(ServiceFactoryI.java:703)
	at Glacier2._SessionDisp.___destroy(_SessionDisp.java:82)

[jmoore]

To test set the timeouts very short:

omero.sessions.sync_force=300000
omero.sessions.sync_interval=60000
omero.sessions.timeout=15000

Create a thumbnail store, wait just a bit, and then close the session:

In [1]: client.sf.createThumbnailStore()
Out[1]: 23da0f01-e5d2-4ddb-ae29-7b6724bfc44f/e7f0d906-f208-4707-93dd-15a71ab8ede3omero.api.ThumbnailStore -t:tcp -h 192.168.178.32 -p 56333:tcp -h 192.168.178.21 -p 56333

In [2]: client.closeSession()

The steps that happen on the server are:

• ServiceFactoryI.destroy catches an exception on SessionManagerImpl.detach
• ServiceFactoryI.doDestroy is called
• CloseableServant.close() is called (calls .close_async())
• preClose is called.
• StatefulServiceInterface.close() is called.
• BasicSecurityWiring.login throws a SessionTimeoutException (i.e. no one is logged in)
• During the finally block, logout() is called which throws the NoSuchElementException

[jmoore]

Solving this by adding a new BasicEventContext subclass -- CloseOnNoSessionContext. When this is detected, most normal handling will be skipped. This shouldn't be a problem because the close() method in StatefulServiceInterface is mostly a marker method, i.e. handlers detect that that is the current method and therefore do proper clean up, but no actual logic should be in the close method itself.

Rather than the long stack trace, this now prints at the WARN level:

2012-01-05 15:31:51,313 WARN  [  ome.security.basic.BasicSecurityWiring] (l.Server-3) SessionTimeoutException on close:ff41408d-8b3a-422c-9fb8-aa4597d193d8

since this possibly points to a client developer error and/or a client crash, since services are not being closed before the session timeouts.

The fix has been pushed to my sprint6-server-backlog branch.

[jmoore <josh@…>]

(In [605cd6c282405260e114bdb21e830ea360a18573/ome.git] on branch develop) Add CloseOnNoSessionContext? for handling close (Fix #6639)