Notice: In order to edit this ticket you need to be either: a Product Owner, The owner or the reporter of the ticket, or, in case of a Task not yet assigned, a team_member"

Task #2973 (closed)

Opened 9 years ago

Closed 8 years ago

Bug: StatefulServiceInterfacePrx.close fails with "connection handle already closed"

Reported by: jamoore Owned by: jamoore
Priority: minor Milestone: OMERO-4.4
Component: General Version: n.a.
Keywords: n.a. Cc:
Resources: n.a. Referenced By: n.a.
References: n.a. Remaining Time: 0.0d
Sprint: 2012-01-17 (6)

Description 

2010-09-12 12:06:31,075 ERROR [ ome.services.blitz.impl.ServiceFactoryI] (.Server-32) Error destroying servant: 86:24:41:33:-68450335:12b0247cac8:-7f92omero.api.RawPixelsStore=ome.services.blitz.impl.RawPixelsStoreI@5cfdaaf
ome.conditions.InternalException:  Wrapped Exception: (org.springframework.transaction.TransactionSystemException):
Could not commit JDBC transaction; nested exception is java.sql.SQLException: connection handle already closed
        at org.springframework.jdbc.datasource.DataSourceTransactionManager.doCommit(DataSourceTransactionManager.java:271)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:412)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:118)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:222)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:111)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
        at $Proxy74.close(Unknown Source)
        at sun.reflect.GeneratedMethodAccessor907.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
        at ome.security.basic.BasicSecurityWiring.invoke(BasicSecurityWiring.java:83)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at ome.services.blitz.fire.AopContextInitializer.invoke(AopContextInitializer.java:40)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
        at $Proxy74.close(Unknown Source)
        at ome.services.blitz.impl.AbstractAmdServant.close_async(AbstractAmdServant.java:223)
        at ome.services.blitz.impl.AbstractAmdServant.close(AbstractAmdServant.java:194)
        at ome.services.blitz.impl.ServiceFactoryI.doDestroy(ServiceFactoryI.java:756)
        at ome.services.blitz.impl.ServiceFactoryI.destroy(ServiceFactoryI.java:669)
        at Glacier2._SessionDisp.___destroy(_SessionDisp.java:82)
        at omero.api._ServiceFactoryDisp.__dispatch(_ServiceFactoryDisp.java:1231)

Change History (7)

comment:1 Changed 9 years ago by jmoore

Script which reproduces:

#!/usr/bin/env python
import threading
import random
import omero
import time
import sys

import logging
import omero.util
omero.util.configure_logging(loglevel=20)

N = 4
c = omero.client("localhost")
c.enableKeepAlive(300)

s = c.createSession("foo", "ome")

event = threading.Event()

fid = c.upload("test.txt").id.val
rfs = s.createRawFileStore()
rfs.setFileId(fid)

def sleep():
    time.sleep(5*random.random())

def go(i):
    count = 0
    while not event.isSet():
        count += 1
        rfs.write([0,1,2,3], i*4, 4)
        sleep()
        if count%100 == 0:
            logging.info("wrote 100")

threads = []
try:
    for i in range(N):
        t = threading.Thread(target=go, args=(i,))
        t.start()
        threads.append(t)
        logging.info("Started %s" % t)
        sleep()

    try:
        sys.stdin.read()
    finally:
        event.set()

    for t in threads:
        t.join()

finally:
    c.closeSession()

comment:2 Changed 9 years ago by jmoore

Longer stack trace:

2010-10-05 10:26:37,870 INFO  [        ome.services.util.ServiceHandler] (l.Server-7)  Meth:	interface ome.api.RawFileStore.write
2010-10-05 10:26:37,870 DEBUG [  ome.security.basic.BasicSecuritySystem] (l.Server-4) Clearing EventLogs.
2010-10-05 10:26:37,870 DEBUG [  ome.security.basic.BasicSecuritySystem] (l.Server-4) Invalidating current EventContext.
2010-10-05 10:26:37,870 INFO  [        ome.services.util.ServiceHandler] (l.Server-7)  Args:	[[0, 1, 2, ... 1 more], 0, 4]
2010-10-05 10:26:37,870 DEBUG [      ome.tools.hibernate.SessionHandler] (l.Server-4) Session bound to thread. Reseting.
2010-10-05 10:26:37,870 DEBUG [      ome.tools.hibernate.SessionHandler] (l.Server-7) Performing action in stateful session.
2010-10-05 10:26:37,870 DEBUG [      ome.tools.hibernate.SessionHandler] (l.Server-7) Binding and reconnecting session.
2010-10-05 10:26:37,870 DEBUG [      ome.tools.hibernate.SessionHandler] (l.Server-7) Binding session to thread.
2010-10-05 10:26:37,872 INFO  [                 org.perf4j.TimingLogger] (l.Server-4) start[1286267197869] time[3] tag[omero.call.success.ome.services.RawFileBean.write]
2010-10-05 10:26:37,872 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Rslt:	null
2010-10-05 10:26:37,874 DEBUG [      ome.tools.hibernate.SessionHandler] (l.Server-7) Session bound to thread. Reseting.
2010-10-05 10:26:37,875 ERROR [ction.interceptor.TransactionInterceptor] (l.Server-7) Application exception overridden by rollback exception
org.hibernate.exception.GenericJDBCException: error executing work
	at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
	at org.hibernate.impl.SessionImpl.doWork(SessionImpl.java:1991)
	at ome.security.basic.EventHandler.invoke(EventHandler.java:114)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at ome.tools.hibernate.SessionHandler.doStateful(SessionHandler.java:182)
	at ome.tools.hibernate.SessionHandler.invoke(SessionHandler.java:166)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:108)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:222)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:111)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
	at $Proxy68.write(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor462.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at ome.security.basic.BasicSecurityWiring.invoke(BasicSecurityWiring.java:83)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at ome.services.blitz.fire.AopContextInitializer.invoke(AopContextInitializer.java:40)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
	at $Proxy68.write(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor463.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at ome.services.blitz.util.IceMethodInvoker.invoke(IceMethodInvoker.java:179)
	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:133)
	at ome.services.blitz.impl.RawFileStoreI.write_async(RawFileStoreI.java:117)
	at omero.api._RawFileStoreTie.write_async(_RawFileStoreTie.java:106)
	at omero.api._RawFileStoreDisp.___write(_RawFileStoreDisp.java:248)
	at omero.api._RawFileStoreDisp.__dispatch(_RawFileStoreDisp.java:379)
	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)
Caused by: java.sql.SQLException: connection handle already closed
	at bitronix.tm.resource.jdbc.JdbcConnectionHandle.getAutoCommit(JdbcConnectionHandle.java:137)
	at org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy$LazyConnectionInvocationHandler.getTargetConnection(LazyConnectionDataSourceProxy.java:406)
	at org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy$LazyConnectionInvocationHandler.invoke(LazyConnectionDataSourceProxy.java:366)
	at $Proxy46.createStatement(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor88.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy$TransactionAwareInvocationHandler.invoke(TransactionAwareDataSourceProxy.java:229)
	at $Proxy46.createStatement(Unknown Source)
	at ome.security.basic.EventHandler$1.execute(EventHandler.java:116)
	at org.hibernate.impl.SessionImpl.doWork(SessionImpl.java:1987)
	... 42 more
2010-10-05 10:26:37,876 INFO  [                 org.perf4j.TimingLogger] (l.Server-7) start[1286267197870] time[6] tag[omero.call.exception]
2010-10-05 10:26:37,877 WARN  [        ome.services.util.ServiceHandler] (l.Server-7) Unknown exception thrown.

org.springframework.transaction.TransactionSystemException: Could not roll back JDBC transaction; nested exception is java.sql.SQLException: connection handle already closed
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doRollback(DataSourceTransactionManager.java:286)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:845)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:822)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:430)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:112)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:222)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:111)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
	at $Proxy68.write(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor462.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at ome.security.basic.BasicSecurityWiring.invoke(BasicSecurityWiring.java:83)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at ome.services.blitz.fire.AopContextInitializer.invoke(AopContextInitializer.java:40)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
	at $Proxy68.write(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor463.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at ome.services.blitz.util.IceMethodInvoker.invoke(IceMethodInvoker.java:179)
	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:133)
	at ome.services.blitz.impl.RawFileStoreI.write_async(RawFileStoreI.java:117)
	at omero.api._RawFileStoreTie.write_async(_RawFileStoreTie.java:106)
	at omero.api._RawFileStoreDisp.___write(_RawFileStoreDisp.java:248)
	at omero.api._RawFileStoreDisp.__dispatch(_RawFileStoreDisp.java:379)
	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)
Caused by: java.sql.SQLException: connection handle already closed
	at bitronix.tm.resource.jdbc.JdbcConnectionHandle.rollback(JdbcConnectionHandle.java:92)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy$LazyConnectionInvocationHandler.invoke(LazyConnectionDataSourceProxy.java:366)
	at $Proxy46.rollback(Unknown Source)
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doRollback(DataSourceTransactionManager.java:283)
	... 40 more
2010-10-05 10:26:37,877 INFO  [        ome.services.util.ServiceHandler] (l.Server-7)  Excp:	org.springframework.transaction.TransactionSystemException: Could not roll back JDBC transaction; nested exception is java.sql.SQLException: connection handle already closed
2010-10-05 10:26:37,877 DEBUG [                    omero.util.IceMapper] (l.Server-7) Handling:
ome.conditions.InternalException:  Wrapped Exception: (org.springframework.transaction.TransactionSystemException):
Could not roll back JDBC transaction; nested exception is java.sql.SQLException: connection handle already closed
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doRollback(DataSourceTransactionManager.java:286)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:845)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:822)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:430)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:112)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:222)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:111)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
	at $Proxy68.write(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor462.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at ome.security.basic.BasicSecurityWiring.invoke(BasicSecurityWiring.java:83)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at ome.services.blitz.fire.AopContextInitializer.invoke(AopContextInitializer.java:40)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
	at $Proxy68.write(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor463.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at ome.services.blitz.util.IceMethodInvoker.invoke(IceMethodInvoker.java:179)
	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:133)
	at ome.services.blitz.impl.RawFileStoreI.write_async(RawFileStoreI.java:117)
	at omero.api._RawFileStoreTie.write_async(_RawFileStoreTie.java:106)
	at omero.api._RawFileStoreDisp.___write(_RawFileStoreDisp.java:248)
	at omero.api._RawFileStoreDisp.__dispatch(_RawFileStoreDisp.java:379)
	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)
2010-10-05 10:26:37,879 DEBUG [                    omero.util.IceMapper] (l.Server-7) Handling:
omero.InternalException
    serverStackTrace = "ome.conditions.InternalException:  Wrapped Exception: (org.springframework.transaction.TransactionSystemException):
                        Could not roll back JDBC transaction; nested exception is java.sql.SQLException: connection handle already closed
                        	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doRollback(DataSourceTransactionManager.java:286)
                        	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:845)
                        	at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:822)
                        	at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:430)
                        	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:112)
                        	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
                        	at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:222)
                        	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
                        	at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:111)
                        	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
                        	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
                        	at $Proxy68.write(Unknown Source)
                        	at sun.reflect.GeneratedMethodAccessor462.invoke(Unknown Source)
                        	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                        	at java.lang.reflect.Method.invoke(Method.java:597)
                        	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
                        	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
                        	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
                        	at ome.security.basic.BasicSecurityWiring.invoke(BasicSecurityWiring.java:83)
                        	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
                        	at ome.services.blitz.fire.AopContextInitializer.invoke(AopContextInitializer.java:40)
                        	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
                        	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
                        	at $Proxy68.write(Unknown Source)
                        	at sun.reflect.GeneratedMethodAccessor463.invoke(Unknown Source)
                        	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                        	at java.lang.reflect.Method.invoke(Method.java:597)
                        	at ome.services.blitz.util.IceMethodInvoker.invoke(IceMethodInvoker.java:179)
                        	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:133)
                        	at ome.services.blitz.impl.RawFileStoreI.write_async(RawFileStoreI.java:117)
                        	at omero.api._RawFileStoreTie.write_async(_RawFileStoreTie.java:106)
                        	at omero.api._RawFileStoreDisp.___write(_RawFileStoreDisp.java:248)
                        	at omero.api._RawFileStoreDisp.__dispatch(_RawFileStoreDisp.java:379)
                        	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 = "ome.conditions.InternalException"
    message = " Wrapped Exception: (org.springframework.transaction.TransactionSystemException):
               Could not roll back JDBC transaction; nested exception is java.sql.SQLException: connection handle already closed"
	at omero.util.IceMapper.handleException(IceMapper.java:1248)
	at ome.services.blitz.util.IceMethodInvoker.invoke(IceMethodInvoker.java:181)
	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:133)
	at ome.services.blitz.impl.RawFileStoreI.write_async(RawFileStoreI.java:117)
	at omero.api._RawFileStoreTie.write_async(_RawFileStoreTie.java:106)
	at omero.api._RawFileStoreDisp.___write(_RawFileStoreDisp.java:248)
	at omero.api._RawFileStoreDisp.__dispatch(_RawFileStoreDisp.java:379)
	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)

comment:3 Changed 9 years ago by jmoore

The application code which is throwing on write is EventHandler 114:

        session.doWork(new Work(){
            public void execute(Connection connection) throws SQLException {
                Statement statement = connection.createStatement();
                statement.execute("set constraints all deferred;");
            }});

comment:4 Changed 8 years ago by jmoore

  • Milestone changed from Unscheduled to OMERO-Beta4.4
  • Owner set to jmoore
  • Sprint set to 2012-01-17 (6)

comment:5 Changed 8 years ago by jmoore

  • Remaining Time set to 0.25
  • Status changed from new to accepted

comment:6 Changed 8 years ago by jmoore

With 4.4, the only exception I'm seeing is the following (which isn't too surprising since RFSes aren't expected to be thread safe):

2012-01-11 11:52:26,900 INFO  [                                    root] (Thread-3  ) wrote 5
2012-01-11 11:52:28,660 INFO  [                                    root] (Thread-2  ) wrote 5
2012-01-11 11:52:28,997 INFO  [                                    root] (Thread-5  ) wrote 5
2012-01-11 11:52:29,152 INFO  [                                    root] (Thread-4  ) wrote 5
2012-01-11 11:52:30,279 INFO  [                                    root] (Thread-3  ) wrote 5
2012-01-11 11:52:30,891 INFO  [                                    root] (Thread-2  ) wrote 5
2012-01-11 11:52:31,493 INFO  [                                    root] (Thread-3  ) wrote 5
2012-01-11 11:52:31,545 INFO  [                                    root] (Thread-4  ) wrote 5
2012-01-11 11:52:31,961 INFO  [                                    root] (Thread-5  ) wrote 5
/Users/moore/GlencoeSoftware.git/git/omero.git/dist/lib/python/omero_ServerErrors_ice.py:115: DeprecationWarning: BaseException.message has been deprecated as of Python 2.6
  self.message = message
/Users/moore/GlencoeSoftware.git/git/omero.git/dist/lib/python/omero_api_RawFileStore_ice.py:149: DeprecationWarning: BaseException.message has been deprecated as of Python 2.6
  return _M_omero.api.RawFileStore._op_write.invoke(self, ((buf, position, length), _ctx))
/Users/moore/GlencoeSoftware.git/git/omero.git/dist/lib/python/omero_ServerErrors_ice.py:301: DeprecationWarning: BaseException.message has been deprecated as of Python 2.6
  return IcePy.stringifyException(self)
Exception in thread Thread-3:
Traceback (most recent call last):
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/threading.py", line 522, in __bootstrap_inner
    self.run()
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/threading.py", line 477, in run
    self.__target(*self.__args, **self.__kwargs)
  File "t.py", line 32, in go
    rfs.write([0,1,2,3], i*4, 4)
  File "/Users/moore/git/dist/lib/python/omero_api_RawFileStore_ice.py", line 149, in write
    return _M_omero.api.RawFileStore._op_write.invoke(self, ((buf, position, length), _ctx))
InternalException: exception ::omero::InternalException
{
    serverStackTrace = ome.conditions.InternalException: Hibernate session is not re-entrant.
Either you have two threads operating on the same stateful object (don't do this)
 or you have a recursive call (recurse on the unwrapped object). 
	at ome.tools.hibernate.SessionHandler.newOrRestoredSession(SessionHandler.java:257)
	at ome.tools.hibernate.SessionHandler.doStateful(SessionHandler.java:176)
	at ome.tools.hibernate.SessionHandler.invoke(SessionHandler.java:166)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:108)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:231)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:116)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
	at $Proxy78.write(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor472.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at ome.security.basic.BasicSecurityWiring.invoke(BasicSecurityWiring.java:95)
	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 $Proxy78.write(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor473.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at ome.services.blitz.util.IceMethodInvoker.invoke(IceMethodInvoker.java:179)
	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:136)
	at ome.services.blitz.impl.RawFileStoreI.write_async(RawFileStoreI.java:117)
	at omero.api._RawFileStoreTie.write_async(_RawFileStoreTie.java:115)
	at omero.api._RawFileStoreDisp.___write(_RawFileStoreDisp.java:296)
	at omero.api._RawFileStoreDisp.__dispatch(_RawFileStoreDisp.java:427)
	at IceInternal.Incoming.invoke(Incoming.java:159)
	at Ice.ConnectionI.invokeAll(ConnectionI.java:2357)
	at Ice.ConnectionI.dispatch(ConnectionI.java:1208)
	at Ice.ConnectionI.message(ConnectionI.java:1163)
	at IceInternal.ThreadPool.run(ThreadPool.java:302)
	at IceInternal.ThreadPool.access$300(ThreadPool.java:12)
	at IceInternal.ThreadPool$EventHandlerThread.run(ThreadPool.java:643)
	at java.lang.Thread.run(Thread.java:680)

    serverExceptionClass = ome.conditions.InternalException
    message = Hibernate session is not re-entrant.
Either you have two threads operating on the same stateful object (don't do this)
 or you have a recursive call (recurse on the unwrapped object). 
}

2012-01-11 11:52:33,385 INFO  [                                    root] (Thread-2  ) wrote 5
2012-01-11 11:52:34,547 INFO  [                                    root] (Thread-4  ) wrote 5
2012-01-11 11:52:34,944 INFO  [                                    root] (Thread-5  ) wrote 5
2012-01-11 11:52:35,916 INFO  [                                    root] (Thread-2  ) wrote 5
2012-01-11 11:52:37,338 INFO  [                                    root] (Thread-2  ) wrote 5
2012-01-11 11:52:37,430 INFO  [                                    root] (Thread-4  ) wrote 5

comment:7 Changed 8 years ago by jmoore

  • Remaining Time changed from 0.25 to 0
  • Resolution set to worksforme
  • Status changed from accepted to closed

Otherwise, I can't reproduce this issue. Marking as "worksforme" in 4.3+ (though earlier it almost certainly was an issue)

Note: See TracTickets for help on using tickets. You may also have a look at Agilo extensions to the ticket.

1.3.13-PRO © 2008-2011 Agilo Software all rights reserved (this page was served in: 0.80210 sec.)

© 2000-2014 University of Dundee & Open Microscopy Environment. Creative Commons Attribution 3.0 Unported License
OME source code is available under the GNU General public license or through commercial license from Glencoe Software

We're Hiring!