2011-11-10 17:55:56,256 INFO [ ome.services.blitz.Entry] ( main) Creating OMERO.blitz. Please wait... 2011-11-10 17:55:59,254 INFO [ng.ShutdownSafeEhcacheManagerFactoryBean] ( main) Initializing EHCache CacheManager 2011-11-10 17:56:05,787 INFO [ ome.services.fulltext.FullTextAnalyzer] ( main) Initialized FullTextAnalyzer 2011-11-10 17:56:14,188 INFO [ ome.services.db.DatabaseIdentity] ( main) Using LSID format: urn:lsid:export.openmicroscopy.org:%s:b8b6ae42-3456-496e-a6ae-ca0371744f85_%s%s 2011-11-10 17:56:14,822 INFO [ org.perf4j.TimingLogger] ( main) start[1320972974381] time[441] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:14,992 INFO [ org.perf4j.TimingLogger] ( main) start[1320972974823] time[169] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:15,204 INFO [ org.perf4j.TimingLogger] ( main) start[1320972974992] time[212] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:15,976 INFO [ org.perf4j.TimingLogger] ( main) start[1320972975209] time[767] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:16,067 INFO [ org.perf4j.TimingLogger] ( main) start[1320972975976] time[91] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:16,215 INFO [ org.perf4j.TimingLogger] ( main) start[1320972976067] time[148] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:16,421 INFO [ org.perf4j.TimingLogger] ( main) start[1320972976225] time[196] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:17,292 INFO [ org.perf4j.TimingLogger] ( main) start[1320972976421] time[871] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:17,411 INFO [ org.perf4j.TimingLogger] ( main) start[1320972977292] time[119] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:17,523 INFO [ org.perf4j.TimingLogger] ( main) start[1320972977411] time[112] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:17,634 INFO [ org.perf4j.TimingLogger] ( main) start[1320972977523] time[111] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:17,728 INFO [ org.perf4j.TimingLogger] ( main) start[1320972977635] time[93] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:18,004 INFO [ org.perf4j.TimingLogger] ( main) start[1320972977728] time[276] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:18,576 INFO [ org.perf4j.TimingLogger] ( main) start[1320972978004] time[572] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:18,674 INFO [ org.perf4j.TimingLogger] ( main) start[1320972978576] time[98] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:18,766 INFO [ org.perf4j.TimingLogger] ( main) start[1320972978674] time[92] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:18,862 INFO [ org.perf4j.TimingLogger] ( main) start[1320972978766] time[96] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:18,969 INFO [ org.perf4j.TimingLogger] ( main) start[1320972978862] time[107] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:19,074 INFO [ org.perf4j.TimingLogger] ( main) start[1320972978969] time[105] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:19,194 INFO [ org.perf4j.TimingLogger] ( main) start[1320972979075] time[119] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 17:56:21,943 INFO [ ome.io.nio.PixelsService] ( main) PixelsService(path=/OMERO.data, resolver=ome.services.OmeroFilePathResolver@1e481c1, backoff=ome.io.nio.SimpleBackOff(factor=166.9), sizes=ome.io.nio.ConfiguredTileSizes(w=256,h=256,W=3192,H=3192)) 2011-11-10 17:56:22,293 INFO [ ome.services.fulltext.FullTextThread] ( main) Initializing Full-Text Indexer 2011-11-10 17:56:22,309 INFO [ ome.services.pixeldata.PixelDataThread] ( main) Initializing PixelDataThread (create events only) 2011-11-10 17:56:22,353 INFO [ ome.services.util.DBPatchCheck] ( main) Verified database patch: OMERO4.3__0 2011-11-10 17:56:23,158 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 17:56:23,159 INFO [ ome.services.util.ServerVersionCheck] ( main) OMERO Version: 4.3.3-00d1137e-b2894 Ready. 2011-11-10 17:56:23,159 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 17:56:27,285 INFO [ ome.system.UpgradeCheck] ( main) no update needed 2011-11-10 17:56:27,293 INFO [ ome.tools.hibernate.ExtendedMetadata] ( main) Calculating ExtendedMetadata... 2011-11-10 17:56:27,373 INFO [.services.scheduler.SchedulerFactoryBean] ( main) Starting Quartz Scheduler now 2011-11-10 17:56:27,380 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.util.NamespaceCheck.namespaceCheck 2011-11-10 17:56:27,380 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@1535180] 2011-11-10 17:56:28,004 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=201(Internal),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:28,186 INFO [ org.perf4j.TimingLogger] ( main) start[1320972987380] time[806] tag[omero.call.success.ome.services.util.NamespaceCheck$1.doWork] 2011-11-10 17:56:28,186 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: null 2011-11-10 17:56:28,630 INFO [e.services.blitz.util.BlitzConfiguration] ( main) Initializing Ice.Communicator 2011-11-10 17:56:29,524 INFO [ ome.services.blitz.fire.Ring] ( main) Checking cluster 2011-11-10 17:56:29,562 INFO [ ome.services.blitz.fire.Registry] ( main) Found 0 cluster node(s) : [] 2011-11-10 17:56:29,562 INFO [ ome.services.blitz.fire.Ring] ( main) Got 0 cluster uuids : [] 2011-11-10 17:56:29,563 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.getManagerList 2011-11-10 17:56:29,563 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@1535180] 2011-11-10 17:56:29,566 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=null(Internal),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:29,607 INFO [ org.perf4j.TimingLogger] ( main) start[1320972989563] time[44] tag[omero.call.success.ome.services.blitz.fire.Ring$2.doWork] 2011-11-10 17:56:29,607 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: (b0bf41b3-d413-4980-a098-01ee8abbb726) 2011-11-10 17:56:29,608 INFO [ ome.services.blitz.fire.Ring] ( main) Purging node: b0bf41b3-d413-4980-a098-01ee8abbb726 2011-11-10 17:56:29,709 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.executeUpdate - set closed = now() 2011-11-10 17:56:29,709 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@1535180] 2011-11-10 17:56:29,737 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=202(Internal),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:29,746 INFO [ org.perf4j.TimingLogger] ( main) start[1320972989709] time[37] tag[omero.call.success.ome.services.blitz.fire.Ring$3.doWork] 2011-11-10 17:56:29,746 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: 0 2011-11-10 17:56:29,746 INFO [ ome.services.blitz.fire.Ring] ( main) Removed 0 entries with value b0bf41b3-d413-4980-a098-01ee8abbb726 2011-11-10 17:56:29,747 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.setManagerDown 2011-11-10 17:56:29,747 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@1535180] 2011-11-10 17:56:29,769 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=203(Internal),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:29,775 INFO [ org.perf4j.TimingLogger] ( main) start[1320972989747] time[28] tag[omero.call.success.ome.services.blitz.fire.Ring$4.doWork] 2011-11-10 17:56:29,776 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: 1 2011-11-10 17:56:29,776 INFO [ ome.services.blitz.fire.Ring] ( main) Removed manager: b0bf41b3-d413-4980-a098-01ee8abbb726 2011-11-10 17:56:29,776 INFO [ ome.services.blitz.fire.Ring] ( main) handleRingShutdown: b0bf41b3-d413-4980-a098-01ee8abbb726 2011-11-10 17:56:29,778 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.addManager 2011-11-10 17:56:29,778 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@1535180] 2011-11-10 17:56:29,800 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=204(Internal),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:29,805 INFO [ ome.security.basic.CurrentDetails] ( main) Adding log:INSERT,class ome.model.meta.Node,201 2011-11-10 17:56:29,815 INFO [ org.perf4j.TimingLogger] ( main) start[1320972989778] time[37] tag[omero.call.success.ome.services.blitz.fire.Ring$5.doWork] 2011-11-10 17:56:29,816 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: ome.model.meta.Node:Id_201 2011-11-10 17:56:29,821 INFO [ ome.services.blitz.fire.Registry] ( main) Added ClusterNode/8daa927e-dd97-43c0-90a5-01d80ee4b21a to registry 2011-11-10 17:56:29,857 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Initializing repository in /OMERO.data 2011-11-10 17:56:29,923 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.scripts.ScriptRepoHelper.loadAll(true) 2011-11-10 17:56:29,923 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@1535180] 2011-11-10 17:56:29,944 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=205(Internal),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:30,041 INFO [ org.perf4j.TimingLogger] ( main) start[1320972989923] time[118] tag[omero.call.success.ome.services.scripts.ScriptRepoHelper$5.doWork] 2011-11-10 17:56:30,041 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: (ome.model.core.OriginalFile:Id_1, ome.model.core.OriginalFile:Id_2, ome.model.core.OriginalFile:Id_3, ... 10 more) 2011-11-10 17:56:30,042 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Initializing repository in /home/steve/apps/OMERO/OMERO.server-Beta-4.3.3/./lib/scripts 2011-11-10 17:56:30,136 INFO [ ome.services.util.ServiceHandler] (3-thread-1) Executor.doWork -- ome.services.blitz.repo.LegacyRepositoryI.takeover 2011-11-10 17:56:30,137 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Executor.doWork -- ome.services.blitz.repo.ScriptRepositoryI.takeover 2011-11-10 17:56:30,143 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Args: [null, InternalSF@1535180] 2011-11-10 17:56:30,143 INFO [ ome.services.util.ServiceHandler] (3-thread-1) Args: [null, InternalSF@1535180] 2011-11-10 17:56:30,193 INFO [ ome.security.basic.EventHandler] (3-thread-2) Auth: user=0,group=0,event=206(Internal),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:30,259 INFO [ ome.services.blitz.Entry] ( main) OMERO.blitz now accepting connections. 2011-11-10 17:56:30,263 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-2) Opened repository scripts (uuid=ScriptRepo) 2011-11-10 17:56:30,268 INFO [ ome.services.blitz.util.CheckAllJobs] ( Thread-8) Waiting 120 secs. for callbacks 2011-11-10 17:56:30,300 INFO [ ome.services.blitz.fire.Registry] (3-thread-2) Updated InternalRepository-ScriptRepo in registry 2011-11-10 17:56:30,304 INFO [ ome.services.blitz.fire.Registry] (3-thread-2) Updated PublicRepository-ScriptRepo in registry 2011-11-10 17:56:30,311 INFO [ ome.security.basic.EventHandler] (3-thread-1) Auth: user=0,group=0,event=207(Internal),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:30,312 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-2) Repository now active 2011-11-10 17:56:30,320 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-1) Opened repository OMERO.data (uuid=27f05637-0e2a-4b48-aaf5-260e24158d73) 2011-11-10 17:56:30,326 INFO [ ome.services.blitz.fire.Registry] (3-thread-1) Updated InternalRepository-27f05637-0e2a-4b48-aaf5-260e24158d73 in registry 2011-11-10 17:56:30,360 INFO [ org.perf4j.TimingLogger] (3-thread-2) start[1320972990143] time[217] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$GetOrCreateRepo.doWork] 2011-11-10 17:56:30,361 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Rslt: ome.model.core.OriginalFile:Id_14 2011-11-10 17:56:30,362 INFO [ ome.services.blitz.fire.Registry] (3-thread-1) Updated PublicRepository-27f05637-0e2a-4b48-aaf5-260e24158d73 in registry 2011-11-10 17:56:30,363 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-1) Repository now active 2011-11-10 17:56:30,366 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Executor.doWork -- ome.services.blitz.repo.ScriptRepositoryI.getDescription(14) 2011-11-10 17:56:30,367 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Args: [null, InternalSF@1535180] 2011-11-10 17:56:30,368 INFO [ org.perf4j.TimingLogger] (3-thread-1) start[1320972990145] time[223] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$GetOrCreateRepo.doWork] 2011-11-10 17:56:30,368 INFO [ ome.services.util.ServiceHandler] (3-thread-1) Rslt: ome.model.core.OriginalFile:Id_15 2011-11-10 17:56:30,368 INFO [ ome.security.basic.EventHandler] (3-thread-2) Auth: user=0,group=0,event=null(Internal),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:30,369 INFO [ ome.services.util.ServiceHandler] (3-thread-1) Executor.doWork -- ome.services.blitz.repo.LegacyRepositoryI.getDescription(15) 2011-11-10 17:56:30,369 INFO [ ome.services.util.ServiceHandler] (3-thread-1) Args: [null, InternalSF@1535180] 2011-11-10 17:56:30,374 INFO [ ome.security.basic.EventHandler] (3-thread-1) Auth: user=0,group=0,event=null(Internal),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:30,385 INFO [ org.perf4j.TimingLogger] (3-thread-2) start[1320972990367] time[18] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$1.doWork] 2011-11-10 17:56:30,385 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Rslt: ome.model.core.OriginalFile:Id_14 2011-11-10 17:56:30,392 INFO [ org.perf4j.TimingLogger] (3-thread-1) start[1320972990369] time[23] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$1.doWork] 2011-11-10 17:56:30,392 INFO [ ome.services.util.ServiceHandler] (3-thread-1) Rslt: ome.model.core.OriginalFile:Id_15 2011-11-10 17:56:32,764 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 17:56:32,764 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Args: [null, InternalSF@1535180] 2011-11-10 17:56:32,812 INFO [ ome.security.basic.EventHandler] (l.Server-0) Auth: user=0,group=0,event=208(Sessions),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:32,986 INFO [ ome.security.basic.CurrentDetails] (l.Server-0) Adding log:INSERT,class ome.model.meta.Session,717 2011-11-10 17:56:33,024 INFO [ org.perf4j.TimingLogger] (l.Server-0) start[1320972992764] time[260] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 17:56:33,025 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 17:56:33,037 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-0) Created session ServiceFactoryI(session-d677614c-0770-47c7-8e47-1185c13afac1/d7a52c22-8282-4f4c-be8f-a5814ed7a457) for user root (agent=Python service) 2011-11-10 17:56:33,050 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-1) Added servant to adapter: d7a52c22-8282-4f4c-be8f-a5814ed7a457/d677614c-0770-47c7-8e47-1185c13afac1omero.api.IConfig(omero.api._IConfigTie@172cbae) 2011-11-10 17:56:33,064 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Meth: interface ome.api.IConfig.getConfigValue 2011-11-10 17:56:33,064 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Args: [omero.data.dir] 2011-11-10 17:56:33,082 INFO [ ome.security.basic.EventHandler] (l.Server-6) Auth: user=0,group=0,event=209(User),sess=d7a52c22-8282-4f4c-be8f-a5814ed7a457 2011-11-10 17:56:33,087 INFO [ org.perf4j.TimingLogger] (l.Server-6) start[1320972993064] time[23] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue] 2011-11-10 17:56:33,088 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Rslt: /OMERO.data 2011-11-10 17:56:33,090 INFO [e.services.sessions.SessionContext$Count] (l.Server-7) -Reference count: d7a52c22-8282-4f4c-be8f-a5814ed7a457=0 2011-11-10 17:56:33,090 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) doDestroy(ServiceFactoryI(session-d677614c-0770-47c7-8e47-1185c13afac1/d7a52c22-8282-4f4c-be8f-a5814ed7a457)) 2011-11-10 17:56:33,091 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Unregistered servant:d7a52c22-8282-4f4c-be8f-a5814ed7a457/d677614c-0770-47c7-8e47-1185c13afac1omero.api.IConfig(omero.api._IConfigTie@172cbae) 2011-11-10 17:56:33,091 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Removed servant from adapter: d677614c-0770-47c7-8e47-1185c13afac1omero.api.IConfig 2011-11-10 17:56:33,091 INFO [ome.services.sessions.SessionManagerImpl] (l.Server-7) closeSession called and no more references: d7a52c22-8282-4f4c-be8f-a5814ed7a457 2011-11-10 17:56:33,092 INFO [ome.services.sessions.state.SessionCache] (l.Server-7) Destroying session d7a52c22-8282-4f4c-be8f-a5814ed7a457 due to : Remove session called 2011-11-10 17:56:33,092 INFO [ org.perf4j.TimingLogger] (l.Server-7) start[1320972993027] time[65] tag[omero.session] 2011-11-10 17:56:33,095 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-7) Reaping 1 clients for d7a52c22-8282-4f4c-be8f-a5814ed7a457 2011-11-10 17:56:39,574 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 17:56:39,575 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Args: [null, InternalSF@1535180] 2011-11-10 17:56:39,575 INFO [ ome.services.util.ServiceHandler] (l.Server-8) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 17:56:39,575 INFO [ ome.services.util.ServiceHandler] (l.Server-8) Args: [null, InternalSF@1535180] 2011-11-10 17:56:39,596 INFO [ ome.security.basic.EventHandler] (l.Server-8) Auth: user=0,group=0,event=210(Sessions),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:39,597 INFO [ ome.security.basic.EventHandler] (l.Server-2) Auth: user=0,group=0,event=211(Sessions),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:39,634 INFO [ ome.security.basic.CurrentDetails] (l.Server-2) Adding log:INSERT,class ome.model.meta.Session,718 2011-11-10 17:56:39,643 INFO [ ome.security.basic.CurrentDetails] (l.Server-8) Adding log:INSERT,class ome.model.meta.Session,719 2011-11-10 17:56:39,656 INFO [ org.perf4j.TimingLogger] (l.Server-2) start[1320972999575] time[81] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 17:56:39,657 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 17:56:39,658 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-2) Created session ServiceFactoryI(session-a3ed1187-2c3a-4daf-a0fc-bef818da7034/07cd4576-679c-49b7-aa2a-85fc89a99f91) for user root (agent=Python service) 2011-11-10 17:56:39,664 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-5) Added servant to adapter: 07cd4576-679c-49b7-aa2a-85fc89a99f91/a3ed1187-2c3a-4daf-a0fc-bef818da7034omero.api.IConfig(omero.api._IConfigTie@9c9874) 2011-11-10 17:56:39,666 INFO [ ome.services.util.ServiceHandler] (l.Server-1) Meth: interface ome.api.IConfig.getConfigValue 2011-11-10 17:56:39,666 INFO [ ome.services.util.ServiceHandler] (l.Server-1) Args: [omero.data.dir] 2011-11-10 17:56:39,668 INFO [ org.perf4j.TimingLogger] (l.Server-8) start[1320972999575] time[93] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 17:56:39,668 INFO [ ome.services.util.ServiceHandler] (l.Server-8) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 17:56:39,668 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-8) Created session ServiceFactoryI(session-a063cad6-e19e-4ff5-8031-130b6345f310/3f7d3421-3a80-4b7e-9151-fe29080f8e89) for user root (agent=Python service) 2011-11-10 17:56:39,687 INFO [ ome.security.basic.EventHandler] (l.Server-1) Auth: user=0,group=0,event=212(User),sess=07cd4576-679c-49b7-aa2a-85fc89a99f91 2011-11-10 17:56:39,688 INFO [ ome.services.blitz.util.CheckAllJobs] (l.Server-4) Received 0 job(s) 2011-11-10 17:56:39,694 INFO [ org.perf4j.TimingLogger] (l.Server-1) start[1320972999666] time[28] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue] 2011-11-10 17:56:39,694 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-9) Added servant to adapter: 3f7d3421-3a80-4b7e-9151-fe29080f8e89/a063cad6-e19e-4ff5-8031-130b6345f310omero.grid.SharedResources(omero.grid._SharedResourcesTie@4a17d8) 2011-11-10 17:56:39,694 INFO [ ome.services.util.ServiceHandler] (l.Server-1) Rslt: /OMERO.data 2011-11-10 17:56:39,697 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Meth: interface ome.api.IConfig.getDatabaseUuid 2011-11-10 17:56:39,697 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Args: () 2011-11-10 17:56:39,719 INFO [ ome.security.basic.EventHandler] (l.Server-2) Auth: user=0,group=0,event=213(User),sess=07cd4576-679c-49b7-aa2a-85fc89a99f91 2011-11-10 17:56:39,725 INFO [ org.perf4j.TimingLogger] (l.Server-2) start[1320972999697] time[28] tag[omero.call.success.ome.logic.ConfigImpl.getDatabaseUuid] 2011-11-10 17:56:39,726 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Rslt: b8b6ae42-3456-496e-a6ae-ca0371744f85 2011-11-10 17:56:39,754 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Added servant to adapter: 07cd4576-679c-49b7-aa2a-85fc89a99f91/a3ed1187-2c3a-4daf-a0fc-bef818da7034omero.api.IQuery(omero.api._IQueryTie@1be469) 2011-11-10 17:56:39,764 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Meth: interface ome.api.IQuery.findByQuery 2011-11-10 17:56:39,764 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Args: [select f from OriginalFile f where sha1 = :uuid, PARAMS:uuid=27f05637-0e2a-4b48-aaf5-260e24158d73 ] 2011-11-10 17:56:39,766 INFO [ ome.security.basic.EventHandler] (l.Server-6) Auth: user=0,group=0,event=null(User),sess=07cd4576-679c-49b7-aa2a-85fc89a99f91 2011-11-10 17:56:39,774 INFO [ org.perf4j.TimingLogger] (l.Server-6) start[1320972999764] time[10] tag[omero.call.success.ome.logic.QueryImpl.findByQuery] 2011-11-10 17:56:39,774 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Rslt: ome.model.core.OriginalFile:Id_15 2011-11-10 17:56:53,334 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Executor.doWork -- ome.services.sessions.SessionManagerImpl.executeCheckPasswordRO(steveo) 2011-11-10 17:56:53,334 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Args: [null, InternalSF@1535180] 2011-11-10 17:56:53,336 INFO [ ome.security.basic.EventHandler] (l.Server-0) Auth: user=0,group=0,event=null(Sessions),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:53,338 INFO [ org.perf4j.TimingLogger] (l.Server-0) start[1320973013334] time[4] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$8.doWork] 2011-11-10 17:56:53,338 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Rslt: null 2011-11-10 17:56:53,339 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Executor.doWork -- ome.services.sessions.SessionManagerImpl.executeCheckPasswordRW(steveo) 2011-11-10 17:56:53,339 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Args: [null, InternalSF@1535180] 2011-11-10 17:56:53,378 INFO [ ome.security.basic.EventHandler] (l.Server-0) Auth: user=0,group=0,event=214(Sessions),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:56:53,924 INFO [ ome.security.auth.LdapPasswordProvider] (l.Server-0) Default choice on create user: steveo (ome.conditions.ApiUsageException: Cannot find unique DistinguishedName: found=0) 2011-11-10 17:56:53,925 INFO [ org.perf4j.TimingLogger] (l.Server-0) start[1320973013339] time[586] tag[omero.call.exception] 2011-11-10 17:56:53,928 WARN [ ome.services.util.ServiceHandler] (l.Server-0) Unknown exception thrown. java.lang.NullPointerException at ome.security.auth.LdapPasswordProvider.checkPassword(LdapPasswordProvider.java:106) at ome.security.auth.PasswordProviders.checkPassword(PasswordProviders.java:42) at ome.logic.AdminImpl.checkPassword(AdminImpl.java:1194) at ome.services.sessions.SessionManagerImpl$9.doWork(SessionManagerImpl.java:978) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:616) 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.services.util.Executor$Impl$Interceptor.invoke(Executor.java:440) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at ome.security.basic.EventHandler.invoke(EventHandler.java:150) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111) 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 $Proxy64.doWork(Unknown Source) at ome.services.util.Executor$Impl.execute(Executor.java:371) at ome.services.sessions.SessionManagerImpl.executeCheckPasswordRW(SessionManagerImpl.java:973) at ome.services.sessions.SessionManagerImpl.executeCheckPassword(SessionManagerImpl.java:945) at ome.services.sessions.SessionManagerImpl.executePasswordCheck(SessionManagerImpl.java:920) at ome.services.blitz.fire.PermissionsVerifierI.checkPermissions(PermissionsVerifierI.java:135) at Glacier2._PermissionsVerifierDisp.___checkPermissions(_PermissionsVerifierDisp.java:90) at Glacier2._PermissionsVerifierDisp.__dispatch(_PermissionsVerifierDisp.java:118) 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) 2011-11-10 17:56:53,929 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Excp: java.lang.NullPointerException 2011-11-10 17:56:53,929 ERROR [services.blitz.fire.PermissionsVerifierI] (l.Server-0) Exception thrown while checking password for:steveo ome.conditions.InternalException: Wrapped Exception: (java.lang.NullPointerException): null at ome.security.auth.LdapPasswordProvider.checkPassword(LdapPasswordProvider.java:106) at ome.security.auth.PasswordProviders.checkPassword(PasswordProviders.java:42) at ome.logic.AdminImpl.checkPassword(AdminImpl.java:1194) at ome.services.sessions.SessionManagerImpl$9.doWork(SessionManagerImpl.java:978) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:616) 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.services.util.Executor$Impl$Interceptor.invoke(Executor.java:440) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at ome.security.basic.EventHandler.invoke(EventHandler.java:150) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111) 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 $Proxy64.doWork(Unknown Source) at ome.services.util.Executor$Impl.execute(Executor.java:371) at ome.services.sessions.SessionManagerImpl.executeCheckPasswordRW(SessionManagerImpl.java:973) at ome.services.sessions.SessionManagerImpl.executeCheckPassword(SessionManagerImpl.java:945) at ome.services.sessions.SessionManagerImpl.executePasswordCheck(SessionManagerImpl.java:920) at ome.services.blitz.fire.PermissionsVerifierI.checkPermissions(PermissionsVerifierI.java:135) at Glacier2._PermissionsVerifierDisp.___checkPermissions(_PermissionsVerifierDisp.java:90) at Glacier2._PermissionsVerifierDisp.__dispatch(_PermissionsVerifierDisp.java:118) 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) 2011-11-10 17:57:00,018 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-3) Performing requestHeartbeats 2011-11-10 17:57:42,092 WARN [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-9) Adapter already deactivated. Cannot remove: Ice.Identity@3b82724 2011-11-10 17:57:42,093 INFO [e.services.sessions.SessionContext$Count] (l.Server-9) -Reference count: 07cd4576-679c-49b7-aa2a-85fc89a99f91=0 2011-11-10 17:57:42,093 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-9) doDestroy(ServiceFactoryI(session-a3ed1187-2c3a-4daf-a0fc-bef818da7034/07cd4576-679c-49b7-aa2a-85fc89a99f91)) 2011-11-10 17:57:42,093 WARN [ ome.services.blitz.impl.QueryI] (l.Server-9) ObjectAdapter deactivated! 2011-11-10 17:57:42,160 ERROR [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-9) Error destroying servant: a3ed1187-2c3a-4daf-a0fc-bef818da7034omero.api.IQuery=ome.services.blitz.impl.QueryI@1be469 java.lang.RuntimeException: omero.ShutdownInProgress serverStackTrace = "Ice.ObjectAdapterDeactivatedException name = "BlitzAdapter" at Ice.ObjectAdapterI.checkForDeactivation(ObjectAdapterI.java:1028) at Ice.ObjectAdapterI.findFacet(ObjectAdapterI.java:459) at Ice.ObjectAdapterI.find(ObjectAdapterI.java:453) at ome.services.blitz.fire.SessionManagerI.getServiceFactory(SessionManagerI.java:385) at ome.services.blitz.fire.SessionManagerI.onApplicationEvent(SessionManagerI.java:277) at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97) at ome.services.messages.GlobalMulticaster.multicastEvent(GlobalMulticaster.java:55) at ome.system.OmeroContext.publishEvent(OmeroContext.java:327) at ome.system.OmeroContext.publishMessage(OmeroContext.java:341) at ome.services.blitz.impl.AbstractAmdServant.close_async(AbstractAmdServant.java:240) 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 = "Ice.ObjectAdapterDeactivatedException" 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) 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) Caused by: omero.ShutdownInProgress serverStackTrace = "Ice.ObjectAdapterDeactivatedException name = "BlitzAdapter" at Ice.ObjectAdapterI.checkForDeactivation(ObjectAdapterI.java:1028) at Ice.ObjectAdapterI.findFacet(ObjectAdapterI.java:459) at Ice.ObjectAdapterI.find(ObjectAdapterI.java:453) at ome.services.blitz.fire.SessionManagerI.getServiceFactory(SessionManagerI.java:385) at ome.services.blitz.fire.SessionManagerI.onApplicationEvent(SessionManagerI.java:277) at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97) at ome.services.messages.GlobalMulticaster.multicastEvent(GlobalMulticaster.java:55) at ome.system.OmeroContext.publishEvent(OmeroContext.java:327) at ome.system.OmeroContext.publishMessage(OmeroContext.java:341) at ome.services.blitz.impl.AbstractAmdServant.close_async(AbstractAmdServant.java:240) 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 = "Ice.ObjectAdapterDeactivatedException" message = (null) at ome.services.blitz.impl.AbstractAmdServant.close_async(AbstractAmdServant.java:243) ... 11 more 2011-11-10 17:57:42,209 INFO [ ome.services.blitz.Entry] ( main) Calling close on context OMERO.blitz 2011-11-10 17:57:42,210 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Releasing /home/steve/apps/OMERO/OMERO.server-Beta-4.3.3/./lib/scripts 2011-11-10 17:57:42,211 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Releasing /OMERO.data 2011-11-10 17:57:42,214 INFO [ ome.services.blitz.fire.Registry] ( main) Removed ClusterNode/8daa927e-dd97-43c0-90a5-01d80ee4b21a from registry 2011-11-10 17:57:42,216 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.executeUpdate - set closed = now() 2011-11-10 17:57:42,216 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@1535180] 2011-11-10 17:57:42,381 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=215(Internal),sess=8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:57:42,437 INFO [ org.perf4j.TimingLogger] ( main) start[1320973062216] time[221] tag[omero.call.success.ome.services.blitz.fire.Ring$3.doWork] 2011-11-10 17:57:42,437 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: 2 2011-11-10 17:57:42,438 INFO [ ome.services.blitz.fire.Ring] ( main) Removed 2 entries for 8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 17:57:42,438 INFO [ ome.services.blitz.fire.Ring] ( main) Disconnected from OMERO.cluster 2011-11-10 17:57:42,439 INFO [ ome.services.blitz.fire.Registry] ( main) Found 0 cluster node(s) : [] 2011-11-10 17:57:42,439 INFO [e.services.blitz.util.BlitzConfiguration] ( main) Shutting down Ice.Communicator 2011-11-10 17:57:42,455 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 17:57:42,455 INFO [ ome.services.util.ServerVersionCheck] ( main) Stopping OMERO... 2011-11-10 17:57:42,455 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 17:57:42,455 INFO [ ome.services.pixeldata.PixelDataThread] ( main) Shutting down PixelDataThread 2011-11-10 17:57:42,456 INFO [ ome.services.fulltext.FullTextThread] ( main) Shutting down Full-Text Indexer 2011-11-10 17:57:42,457 INFO [.services.scheduler.SchedulerFactoryBean] ( main) Shutting down Quartz Scheduler 2011-11-10 17:57:42,468 INFO [ng.ShutdownSafeEhcacheManagerFactoryBean] ( main) Shutting down EHCache CacheManager 2011-11-10 17:57:42,468 INFO [ ome.services.blitz.Entry] ( main) Finished shutdown. 2011-11-10 18:08:15,373 INFO [ ome.services.blitz.Entry] ( main) Creating OMERO.blitz. Please wait... 2011-11-10 18:08:18,216 INFO [ng.ShutdownSafeEhcacheManagerFactoryBean] ( main) Initializing EHCache CacheManager 2011-11-10 18:08:25,364 INFO [ ome.services.fulltext.FullTextAnalyzer] ( main) Initialized FullTextAnalyzer 2011-11-10 18:08:32,961 INFO [ ome.services.db.DatabaseIdentity] ( main) Using LSID format: urn:lsid:export.openmicroscopy.org:%s:b8b6ae42-3456-496e-a6ae-ca0371744f85_%s%s 2011-11-10 18:08:33,917 INFO [ org.perf4j.TimingLogger] ( main) start[1320973713061] time[856] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:34,119 INFO [ org.perf4j.TimingLogger] ( main) start[1320973713919] time[200] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:34,359 INFO [ org.perf4j.TimingLogger] ( main) start[1320973714119] time[240] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:35,123 INFO [ org.perf4j.TimingLogger] ( main) start[1320973714366] time[756] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:35,239 INFO [ org.perf4j.TimingLogger] ( main) start[1320973715123] time[116] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:35,363 INFO [ org.perf4j.TimingLogger] ( main) start[1320973715239] time[124] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:35,460 INFO [ org.perf4j.TimingLogger] ( main) start[1320973715364] time[96] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:36,120 INFO [ org.perf4j.TimingLogger] ( main) start[1320973715460] time[659] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:36,253 INFO [ org.perf4j.TimingLogger] ( main) start[1320973716120] time[133] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:36,376 INFO [ org.perf4j.TimingLogger] ( main) start[1320973716254] time[122] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:36,487 INFO [ org.perf4j.TimingLogger] ( main) start[1320973716377] time[110] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:36,576 INFO [ org.perf4j.TimingLogger] ( main) start[1320973716487] time[89] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:36,715 INFO [ org.perf4j.TimingLogger] ( main) start[1320973716576] time[139] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:36,893 INFO [ org.perf4j.TimingLogger] ( main) start[1320973716716] time[177] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:37,378 INFO [ org.perf4j.TimingLogger] ( main) start[1320973716893] time[485] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:37,505 INFO [ org.perf4j.TimingLogger] ( main) start[1320973717378] time[127] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:37,606 INFO [ org.perf4j.TimingLogger] ( main) start[1320973717505] time[101] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:37,699 INFO [ org.perf4j.TimingLogger] ( main) start[1320973717606] time[93] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:37,789 INFO [ org.perf4j.TimingLogger] ( main) start[1320973717699] time[90] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:37,900 INFO [ org.perf4j.TimingLogger] ( main) start[1320973717789] time[111] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:08:37,910 INFO [ ome.io.nio.PixelsService] ( main) PixelsService(path=/OMERO.data, resolver=ome.services.OmeroFilePathResolver@c05c2, backoff=ome.io.nio.SimpleBackOff(factor=152.2), sizes=ome.io.nio.ConfiguredTileSizes(w=256,h=256,W=3192,H=3192)) 2011-11-10 18:08:38,137 INFO [ ome.services.fulltext.FullTextThread] ( main) Initializing Full-Text Indexer 2011-11-10 18:08:38,151 INFO [ ome.services.pixeldata.PixelDataThread] ( main) Initializing PixelDataThread (create events only) 2011-11-10 18:08:38,164 INFO [ ome.services.util.DBPatchCheck] ( main) Verified database patch: OMERO4.3__0 2011-11-10 18:08:40,955 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 18:08:40,956 INFO [ ome.services.util.ServerVersionCheck] ( main) OMERO Version: 4.3.3-00d1137e-b2894 Ready. 2011-11-10 18:08:40,956 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 18:08:44,620 INFO [ ome.system.UpgradeCheck] ( main) no update needed 2011-11-10 18:08:44,633 INFO [ ome.tools.hibernate.ExtendedMetadata] ( main) Calculating ExtendedMetadata... 2011-11-10 18:08:44,719 INFO [.services.scheduler.SchedulerFactoryBean] ( main) Starting Quartz Scheduler now 2011-11-10 18:08:44,725 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.util.NamespaceCheck.namespaceCheck 2011-11-10 18:08:44,725 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@13208327] 2011-11-10 18:08:44,983 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=251(Internal),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:45,495 INFO [ org.perf4j.TimingLogger] ( main) start[1320973724725] time[770] tag[omero.call.success.ome.services.util.NamespaceCheck$1.doWork] 2011-11-10 18:08:45,495 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: null 2011-11-10 18:08:45,672 INFO [e.services.blitz.util.BlitzConfiguration] ( main) Initializing Ice.Communicator 2011-11-10 18:08:45,988 INFO [ ome.services.blitz.fire.Ring] ( main) Checking cluster 2011-11-10 18:08:46,027 INFO [ ome.services.blitz.fire.Registry] ( main) Found 0 cluster node(s) : [] 2011-11-10 18:08:46,028 INFO [ ome.services.blitz.fire.Ring] ( main) Got 0 cluster uuids : [] 2011-11-10 18:08:46,031 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.getManagerList 2011-11-10 18:08:46,031 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@13208327] 2011-11-10 18:08:46,045 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=null(Internal),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:46,056 INFO [ org.perf4j.TimingLogger] ( main) start[1320973726031] time[25] tag[omero.call.success.ome.services.blitz.fire.Ring$2.doWork] 2011-11-10 18:08:46,056 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: (8daa927e-dd97-43c0-90a5-01d80ee4b21a) 2011-11-10 18:08:46,056 INFO [ ome.services.blitz.fire.Ring] ( main) Purging node: 8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 18:08:46,526 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.executeUpdate - set closed = now() 2011-11-10 18:08:46,527 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@13208327] 2011-11-10 18:08:46,556 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=252(Internal),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:46,565 INFO [ org.perf4j.TimingLogger] ( main) start[1320973726527] time[38] tag[omero.call.success.ome.services.blitz.fire.Ring$3.doWork] 2011-11-10 18:08:46,565 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: 0 2011-11-10 18:08:46,565 INFO [ ome.services.blitz.fire.Ring] ( main) Removed 0 entries with value 8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 18:08:46,566 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.setManagerDown 2011-11-10 18:08:46,566 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@13208327] 2011-11-10 18:08:46,586 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=253(Internal),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:46,592 INFO [ org.perf4j.TimingLogger] ( main) start[1320973726566] time[26] tag[omero.call.success.ome.services.blitz.fire.Ring$4.doWork] 2011-11-10 18:08:46,592 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: 1 2011-11-10 18:08:46,592 INFO [ ome.services.blitz.fire.Ring] ( main) Removed manager: 8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 18:08:46,592 INFO [ ome.services.blitz.fire.Ring] ( main) handleRingShutdown: 8daa927e-dd97-43c0-90a5-01d80ee4b21a 2011-11-10 18:08:46,593 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.addManager 2011-11-10 18:08:46,593 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@13208327] 2011-11-10 18:08:46,616 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=254(Internal),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:46,623 INFO [ ome.security.basic.CurrentDetails] ( main) Adding log:INSERT,class ome.model.meta.Node,251 2011-11-10 18:08:46,639 INFO [ org.perf4j.TimingLogger] ( main) start[1320973726593] time[46] tag[omero.call.success.ome.services.blitz.fire.Ring$5.doWork] 2011-11-10 18:08:46,639 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: ome.model.meta.Node:Id_251 2011-11-10 18:08:46,646 INFO [ ome.services.blitz.fire.Registry] ( main) Added ClusterNode/281e364d-4a80-40b8-90b2-a2235801f2c7 to registry 2011-11-10 18:08:46,674 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Initializing repository in /OMERO.data 2011-11-10 18:08:46,724 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.scripts.ScriptRepoHelper.loadAll(true) 2011-11-10 18:08:46,724 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@13208327] 2011-11-10 18:08:46,744 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=255(Internal),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:46,840 INFO [ org.perf4j.TimingLogger] ( main) start[1320973726725] time[115] tag[omero.call.success.ome.services.scripts.ScriptRepoHelper$5.doWork] 2011-11-10 18:08:46,841 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: (ome.model.core.OriginalFile:Id_1, ome.model.core.OriginalFile:Id_2, ome.model.core.OriginalFile:Id_3, ... 10 more) 2011-11-10 18:08:46,842 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Initializing repository in /home/steve/apps/OMERO/OMERO.server-Beta-4.3.3/./lib/scripts 2011-11-10 18:08:46,904 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Executor.doWork -- ome.services.blitz.repo.ScriptRepositoryI.takeover 2011-11-10 18:08:46,908 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Args: [null, InternalSF@13208327] 2011-11-10 18:08:46,905 INFO [ ome.services.util.ServiceHandler] (3-thread-1) Executor.doWork -- ome.services.blitz.repo.LegacyRepositoryI.takeover 2011-11-10 18:08:46,909 INFO [ ome.services.util.ServiceHandler] (3-thread-1) Args: [null, InternalSF@13208327] 2011-11-10 18:08:46,943 INFO [ ome.services.blitz.Entry] ( main) OMERO.blitz now accepting connections. 2011-11-10 18:08:46,945 INFO [ ome.services.blitz.util.CheckAllJobs] ( Thread-8) Waiting 120 secs. for callbacks 2011-11-10 18:08:46,973 INFO [ ome.security.basic.EventHandler] (3-thread-1) Auth: user=0,group=0,event=256(Internal),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:46,989 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-1) Opened repository OMERO.data (uuid=27f05637-0e2a-4b48-aaf5-260e24158d73) 2011-11-10 18:08:47,023 INFO [ ome.services.blitz.fire.Registry] (3-thread-1) Updated InternalRepository-27f05637-0e2a-4b48-aaf5-260e24158d73 in registry 2011-11-10 18:08:47,028 INFO [ ome.services.blitz.fire.Registry] (3-thread-1) Updated PublicRepository-27f05637-0e2a-4b48-aaf5-260e24158d73 in registry 2011-11-10 18:08:47,041 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-1) Repository now active 2011-11-10 18:08:47,047 INFO [ org.perf4j.TimingLogger] (3-thread-1) start[1320973726909] time[138] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$GetOrCreateRepo.doWork] 2011-11-10 18:08:47,048 INFO [ ome.services.util.ServiceHandler] (3-thread-1) Rslt: ome.model.core.OriginalFile:Id_15 2011-11-10 18:08:47,049 INFO [ ome.services.util.ServiceHandler] (3-thread-1) Executor.doWork -- ome.services.blitz.repo.LegacyRepositoryI.getDescription(15) 2011-11-10 18:08:47,049 INFO [ ome.services.util.ServiceHandler] (3-thread-1) Args: [null, InternalSF@13208327] 2011-11-10 18:08:47,053 INFO [ ome.security.basic.EventHandler] (3-thread-1) Auth: user=0,group=0,event=null(Internal),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:47,067 INFO [ ome.security.basic.EventHandler] (3-thread-2) Auth: user=0,group=0,event=257(Internal),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:47,075 INFO [ org.perf4j.TimingLogger] (3-thread-1) start[1320973727049] time[26] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$1.doWork] 2011-11-10 18:08:47,077 INFO [ ome.services.util.ServiceHandler] (3-thread-1) Rslt: ome.model.core.OriginalFile:Id_15 2011-11-10 18:08:47,082 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-2) Opened repository scripts (uuid=ScriptRepo) 2011-11-10 18:08:47,086 INFO [ ome.services.blitz.fire.Registry] (3-thread-2) Updated InternalRepository-ScriptRepo in registry 2011-11-10 18:08:47,089 INFO [ ome.services.blitz.fire.Registry] (3-thread-2) Updated PublicRepository-ScriptRepo in registry 2011-11-10 18:08:47,089 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-2) Repository now active 2011-11-10 18:08:47,093 INFO [ org.perf4j.TimingLogger] (3-thread-2) start[1320973726908] time[185] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$GetOrCreateRepo.doWork] 2011-11-10 18:08:47,093 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Rslt: ome.model.core.OriginalFile:Id_14 2011-11-10 18:08:47,093 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Executor.doWork -- ome.services.blitz.repo.ScriptRepositoryI.getDescription(14) 2011-11-10 18:08:47,093 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Args: [null, InternalSF@13208327] 2011-11-10 18:08:47,095 INFO [ ome.security.basic.EventHandler] (3-thread-2) Auth: user=0,group=0,event=null(Internal),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:47,110 INFO [ org.perf4j.TimingLogger] (3-thread-2) start[1320973727093] time[17] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$1.doWork] 2011-11-10 18:08:47,110 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Rslt: ome.model.core.OriginalFile:Id_14 2011-11-10 18:08:49,010 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 18:08:49,011 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Args: [null, InternalSF@13208327] 2011-11-10 18:08:49,034 INFO [ ome.security.basic.EventHandler] (l.Server-2) Auth: user=0,group=0,event=258(Sessions),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:49,073 INFO [ ome.security.basic.CurrentDetails] (l.Server-2) Adding log:INSERT,class ome.model.meta.Session,870 2011-11-10 18:08:49,110 INFO [ org.perf4j.TimingLogger] (l.Server-2) start[1320973729011] time[99] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 18:08:49,110 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:08:49,121 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-2) Created session ServiceFactoryI(session-09c27b9c-3e0e-4cb3-9430-53f0e65eace9/e3408f7e-545a-45e1-bf93-23ddc54c4a13) for user root (agent=Python service) 2011-11-10 18:08:49,134 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-9) Added servant to adapter: e3408f7e-545a-45e1-bf93-23ddc54c4a13/09c27b9c-3e0e-4cb3-9430-53f0e65eace9omero.api.IConfig(omero.api._IConfigTie@812051) 2011-11-10 18:08:49,148 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Meth: interface ome.api.IConfig.getConfigValue 2011-11-10 18:08:49,148 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Args: [omero.data.dir] 2011-11-10 18:08:49,165 INFO [ ome.security.basic.EventHandler] (l.Server-6) Auth: user=0,group=0,event=259(User),sess=e3408f7e-545a-45e1-bf93-23ddc54c4a13 2011-11-10 18:08:49,170 INFO [ org.perf4j.TimingLogger] (l.Server-6) start[1320973729148] time[22] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue] 2011-11-10 18:08:49,170 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Rslt: /OMERO.data 2011-11-10 18:08:49,173 INFO [e.services.sessions.SessionContext$Count] (l.Server-4) -Reference count: e3408f7e-545a-45e1-bf93-23ddc54c4a13=0 2011-11-10 18:08:49,173 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-4) doDestroy(ServiceFactoryI(session-09c27b9c-3e0e-4cb3-9430-53f0e65eace9/e3408f7e-545a-45e1-bf93-23ddc54c4a13)) 2011-11-10 18:08:49,174 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-4) Unregistered servant:e3408f7e-545a-45e1-bf93-23ddc54c4a13/09c27b9c-3e0e-4cb3-9430-53f0e65eace9omero.api.IConfig(omero.api._IConfigTie@812051) 2011-11-10 18:08:49,174 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-4) Removed servant from adapter: 09c27b9c-3e0e-4cb3-9430-53f0e65eace9omero.api.IConfig 2011-11-10 18:08:49,174 INFO [ome.services.sessions.SessionManagerImpl] (l.Server-4) closeSession called and no more references: e3408f7e-545a-45e1-bf93-23ddc54c4a13 2011-11-10 18:08:49,174 INFO [ome.services.sessions.state.SessionCache] (l.Server-4) Destroying session e3408f7e-545a-45e1-bf93-23ddc54c4a13 due to : Remove session called 2011-11-10 18:08:49,174 INFO [ org.perf4j.TimingLogger] (l.Server-4) start[1320973729113] time[61] tag[omero.session] 2011-11-10 18:08:49,178 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-4) Reaping 1 clients for e3408f7e-545a-45e1-bf93-23ddc54c4a13 2011-11-10 18:08:56,004 INFO [ ome.services.util.ServiceHandler] (l.Server-1) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 18:08:56,005 INFO [ ome.services.util.ServiceHandler] (l.Server-1) Args: [null, InternalSF@13208327] 2011-11-10 18:08:56,010 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 18:08:56,010 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Args: [null, InternalSF@13208327] 2011-11-10 18:08:56,048 INFO [ ome.security.basic.EventHandler] (l.Server-1) Auth: user=0,group=0,event=260(Sessions),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:56,052 INFO [ ome.security.basic.EventHandler] (l.Server-0) Auth: user=0,group=0,event=261(Sessions),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:08:56,066 INFO [ ome.security.basic.CurrentDetails] (l.Server-1) Adding log:INSERT,class ome.model.meta.Session,871 2011-11-10 18:08:56,084 INFO [ org.perf4j.TimingLogger] (l.Server-1) start[1320973736005] time[79] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 18:08:56,084 INFO [ ome.services.util.ServiceHandler] (l.Server-1) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:08:56,085 INFO [ ome.security.basic.CurrentDetails] (l.Server-0) Adding log:INSERT,class ome.model.meta.Session,872 2011-11-10 18:08:56,085 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-1) Created session ServiceFactoryI(session-2e5a127f-4fc3-4943-9c97-81c0c68cea14/8f92eb9b-edbb-4045-973f-41910ec10cca) for user root (agent=Python service) 2011-11-10 18:08:56,093 INFO [ ome.services.blitz.util.CheckAllJobs] (l.Server-9) Received 0 job(s) 2011-11-10 18:08:56,103 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-8) Added servant to adapter: 8f92eb9b-edbb-4045-973f-41910ec10cca/2e5a127f-4fc3-4943-9c97-81c0c68cea14omero.grid.SharedResources(omero.grid._SharedResourcesTie@d6a9a4) 2011-11-10 18:08:56,116 INFO [ org.perf4j.TimingLogger] (l.Server-0) start[1320973736010] time[106] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 18:08:56,116 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:08:56,117 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-0) Created session ServiceFactoryI(session-f294bdeb-a896-4ade-a674-7a9c25855ad8/eac88ab6-3086-41f7-8833-cb50e15ef175) for user root (agent=Python service) 2011-11-10 18:08:56,120 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-4) Added servant to adapter: eac88ab6-3086-41f7-8833-cb50e15ef175/f294bdeb-a896-4ade-a674-7a9c25855ad8omero.api.IConfig(omero.api._IConfigTie@16eeaaa) 2011-11-10 18:08:56,123 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Meth: interface ome.api.IConfig.getConfigValue 2011-11-10 18:08:56,123 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Args: [omero.data.dir] 2011-11-10 18:08:56,141 INFO [ ome.security.basic.EventHandler] (l.Server-6) Auth: user=0,group=0,event=262(User),sess=eac88ab6-3086-41f7-8833-cb50e15ef175 2011-11-10 18:08:56,144 INFO [ org.perf4j.TimingLogger] (l.Server-6) start[1320973736123] time[21] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue] 2011-11-10 18:08:56,144 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Rslt: /OMERO.data 2011-11-10 18:08:56,147 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Meth: interface ome.api.IConfig.getDatabaseUuid 2011-11-10 18:08:56,147 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Args: () 2011-11-10 18:08:56,165 INFO [ ome.security.basic.EventHandler] (l.Server-2) Auth: user=0,group=0,event=263(User),sess=eac88ab6-3086-41f7-8833-cb50e15ef175 2011-11-10 18:08:56,167 INFO [ org.perf4j.TimingLogger] (l.Server-2) start[1320973736147] time[20] tag[omero.call.success.ome.logic.ConfigImpl.getDatabaseUuid] 2011-11-10 18:08:56,167 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Rslt: b8b6ae42-3456-496e-a6ae-ca0371744f85 2011-11-10 18:08:56,182 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-0) Added servant to adapter: eac88ab6-3086-41f7-8833-cb50e15ef175/f294bdeb-a896-4ade-a674-7a9c25855ad8omero.api.IQuery(omero.api._IQueryTie@12fe80) 2011-11-10 18:08:56,192 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Meth: interface ome.api.IQuery.findByQuery 2011-11-10 18:08:56,192 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Args: [select f from OriginalFile f where sha1 = :uuid, PARAMS:uuid=27f05637-0e2a-4b48-aaf5-260e24158d73 ] 2011-11-10 18:08:56,194 INFO [ ome.security.basic.EventHandler] (l.Server-5) Auth: user=0,group=0,event=null(User),sess=eac88ab6-3086-41f7-8833-cb50e15ef175 2011-11-10 18:08:56,201 INFO [ org.perf4j.TimingLogger] (l.Server-5) start[1320973736192] time[9] tag[omero.call.success.ome.logic.QueryImpl.findByQuery] 2011-11-10 18:08:56,201 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Rslt: ome.model.core.OriginalFile:Id_15 2011-11-10 18:09:00,031 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-3) Performing requestHeartbeats 2011-11-10 18:10:03,761 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Executor.doWork -- ome.services.sessions.SessionManagerImpl.executeCheckPasswordRO(steveo) 2011-11-10 18:10:03,761 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Args: [null, InternalSF@13208327] 2011-11-10 18:10:03,762 INFO [ ome.security.basic.EventHandler] (l.Server-0) Auth: user=0,group=0,event=null(Sessions),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:10:03,764 INFO [ org.perf4j.TimingLogger] (l.Server-0) start[1320973803761] time[3] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$8.doWork] 2011-11-10 18:10:03,764 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Rslt: null 2011-11-10 18:10:03,765 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Executor.doWork -- ome.services.sessions.SessionManagerImpl.executeCheckPasswordRW(steveo) 2011-11-10 18:10:03,765 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Args: [null, InternalSF@13208327] 2011-11-10 18:10:03,783 INFO [ ome.security.basic.EventHandler] (l.Server-0) Auth: user=0,group=0,event=264(Sessions),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:10:03,870 INFO [ ome.security.auth.LdapPasswordProvider] (l.Server-0) Default choice on create user: steveo (ome.conditions.ApiUsageException: Cannot find unique DistinguishedName: found=0) 2011-11-10 18:10:03,871 INFO [ org.perf4j.TimingLogger] (l.Server-0) start[1320973803765] time[106] tag[omero.call.exception] 2011-11-10 18:10:03,874 WARN [ ome.services.util.ServiceHandler] (l.Server-0) Unknown exception thrown. java.lang.NullPointerException at ome.security.auth.LdapPasswordProvider.checkPassword(LdapPasswordProvider.java:106) at ome.security.auth.PasswordProviders.checkPassword(PasswordProviders.java:42) at ome.logic.AdminImpl.checkPassword(AdminImpl.java:1194) at ome.services.sessions.SessionManagerImpl$9.doWork(SessionManagerImpl.java:978) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:616) 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.services.util.Executor$Impl$Interceptor.invoke(Executor.java:440) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at ome.security.basic.EventHandler.invoke(EventHandler.java:150) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111) 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 $Proxy64.doWork(Unknown Source) at ome.services.util.Executor$Impl.execute(Executor.java:371) at ome.services.sessions.SessionManagerImpl.executeCheckPasswordRW(SessionManagerImpl.java:973) at ome.services.sessions.SessionManagerImpl.executeCheckPassword(SessionManagerImpl.java:945) at ome.services.sessions.SessionManagerImpl.executePasswordCheck(SessionManagerImpl.java:920) at ome.services.blitz.fire.PermissionsVerifierI.checkPermissions(PermissionsVerifierI.java:135) at Glacier2._PermissionsVerifierDisp.___checkPermissions(_PermissionsVerifierDisp.java:90) at Glacier2._PermissionsVerifierDisp.__dispatch(_PermissionsVerifierDisp.java:118) 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) 2011-11-10 18:10:03,876 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Excp: java.lang.NullPointerException 2011-11-10 18:10:03,876 ERROR [services.blitz.fire.PermissionsVerifierI] (l.Server-0) Exception thrown while checking password for:steveo ome.conditions.InternalException: Wrapped Exception: (java.lang.NullPointerException): null at ome.security.auth.LdapPasswordProvider.checkPassword(LdapPasswordProvider.java:106) at ome.security.auth.PasswordProviders.checkPassword(PasswordProviders.java:42) at ome.logic.AdminImpl.checkPassword(AdminImpl.java:1194) at ome.services.sessions.SessionManagerImpl$9.doWork(SessionManagerImpl.java:978) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:616) 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.services.util.Executor$Impl$Interceptor.invoke(Executor.java:440) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at ome.security.basic.EventHandler.invoke(EventHandler.java:150) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111) 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 $Proxy64.doWork(Unknown Source) at ome.services.util.Executor$Impl.execute(Executor.java:371) at ome.services.sessions.SessionManagerImpl.executeCheckPasswordRW(SessionManagerImpl.java:973) at ome.services.sessions.SessionManagerImpl.executeCheckPassword(SessionManagerImpl.java:945) at ome.services.sessions.SessionManagerImpl.executePasswordCheck(SessionManagerImpl.java:920) at ome.services.blitz.fire.PermissionsVerifierI.checkPermissions(PermissionsVerifierI.java:135) at Glacier2._PermissionsVerifierDisp.___checkPermissions(_PermissionsVerifierDisp.java:90) at Glacier2._PermissionsVerifierDisp.__dispatch(_PermissionsVerifierDisp.java:118) 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) 2011-11-10 18:10:17,271 WARN [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-4) Adapter already deactivated. Cannot remove: Ice.Identity@3521d2f9 2011-11-10 18:10:17,271 INFO [e.services.sessions.SessionContext$Count] (l.Server-4) -Reference count: eac88ab6-3086-41f7-8833-cb50e15ef175=0 2011-11-10 18:10:17,272 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-4) doDestroy(ServiceFactoryI(session-f294bdeb-a896-4ade-a674-7a9c25855ad8/eac88ab6-3086-41f7-8833-cb50e15ef175)) 2011-11-10 18:10:17,273 WARN [ ome.services.blitz.impl.ConfigI] (l.Server-4) ObjectAdapter deactivated! 2011-11-10 18:10:17,274 WARN [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Adapter already deactivated. Cannot remove: Ice.Identity@dd94ae32 2011-11-10 18:10:17,274 INFO [e.services.sessions.SessionContext$Count] (l.Server-7) -Reference count: 8f92eb9b-edbb-4045-973f-41910ec10cca=0 2011-11-10 18:10:17,305 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) doDestroy(ServiceFactoryI(session-2e5a127f-4fc3-4943-9c97-81c0c68cea14/8f92eb9b-edbb-4045-973f-41910ec10cca)) 2011-11-10 18:10:17,305 WARN [ome.services.blitz.impl.SharedResourcesI] (l.Server-7) ObjectAdapter deactivated! 2011-11-10 18:10:17,313 ERROR [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-4) Error destroying servant: f294bdeb-a896-4ade-a674-7a9c25855ad8omero.api.IConfig=ome.services.blitz.impl.ConfigI@16eeaaa java.lang.RuntimeException: omero.ShutdownInProgress serverStackTrace = "Ice.ObjectAdapterDeactivatedException name = "BlitzAdapter" at Ice.ObjectAdapterI.checkForDeactivation(ObjectAdapterI.java:1028) at Ice.ObjectAdapterI.findFacet(ObjectAdapterI.java:459) at Ice.ObjectAdapterI.find(ObjectAdapterI.java:453) at ome.services.blitz.fire.SessionManagerI.getServiceFactory(SessionManagerI.java:385) at ome.services.blitz.fire.SessionManagerI.onApplicationEvent(SessionManagerI.java:277) at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97) at ome.services.messages.GlobalMulticaster.multicastEvent(GlobalMulticaster.java:55) at ome.system.OmeroContext.publishEvent(OmeroContext.java:327) at ome.system.OmeroContext.publishMessage(OmeroContext.java:341) at ome.services.blitz.impl.AbstractAmdServant.close_async(AbstractAmdServant.java:240) 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 = "Ice.ObjectAdapterDeactivatedException" 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) 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) Caused by: omero.ShutdownInProgress serverStackTrace = "Ice.ObjectAdapterDeactivatedException name = "BlitzAdapter" at Ice.ObjectAdapterI.checkForDeactivation(ObjectAdapterI.java:1028) at Ice.ObjectAdapterI.findFacet(ObjectAdapterI.java:459) at Ice.ObjectAdapterI.find(ObjectAdapterI.java:453) at ome.services.blitz.fire.SessionManagerI.getServiceFactory(SessionManagerI.java:385) at ome.services.blitz.fire.SessionManagerI.onApplicationEvent(SessionManagerI.java:277) at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97) at ome.services.messages.GlobalMulticaster.multicastEvent(GlobalMulticaster.java:55) at ome.system.OmeroContext.publishEvent(OmeroContext.java:327) at ome.system.OmeroContext.publishMessage(OmeroContext.java:341) at ome.services.blitz.impl.AbstractAmdServant.close_async(AbstractAmdServant.java:240) 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 = "Ice.ObjectAdapterDeactivatedException" message = (null) at ome.services.blitz.impl.AbstractAmdServant.close_async(AbstractAmdServant.java:243) ... 11 more 2011-11-10 18:10:17,318 ERROR [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Error destroying servant: 2e5a127f-4fc3-4943-9c97-81c0c68cea14omero.grid.SharedResources=ome.services.blitz.impl.SharedResourcesI@d6a9a4 java.lang.RuntimeException: omero.ShutdownInProgress serverStackTrace = "Ice.ObjectAdapterDeactivatedException name = "BlitzAdapter" at Ice.ObjectAdapterI.checkForDeactivation(ObjectAdapterI.java:1028) at Ice.ObjectAdapterI.findFacet(ObjectAdapterI.java:459) at Ice.ObjectAdapterI.find(ObjectAdapterI.java:453) at ome.services.blitz.fire.SessionManagerI.getServiceFactory(SessionManagerI.java:385) at ome.services.blitz.fire.SessionManagerI.onApplicationEvent(SessionManagerI.java:277) at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97) at ome.services.messages.GlobalMulticaster.multicastEvent(GlobalMulticaster.java:55) at ome.system.OmeroContext.publishEvent(OmeroContext.java:327) at ome.system.OmeroContext.publishMessage(OmeroContext.java:341) at ome.services.blitz.impl.AbstractAmdServant.close_async(AbstractAmdServant.java:240) 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 = "Ice.ObjectAdapterDeactivatedException" 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) 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) Caused by: omero.ShutdownInProgress serverStackTrace = "Ice.ObjectAdapterDeactivatedException name = "BlitzAdapter" at Ice.ObjectAdapterI.checkForDeactivation(ObjectAdapterI.java:1028) at Ice.ObjectAdapterI.findFacet(ObjectAdapterI.java:459) at Ice.ObjectAdapterI.find(ObjectAdapterI.java:453) at ome.services.blitz.fire.SessionManagerI.getServiceFactory(SessionManagerI.java:385) at ome.services.blitz.fire.SessionManagerI.onApplicationEvent(SessionManagerI.java:277) at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97) at ome.services.messages.GlobalMulticaster.multicastEvent(GlobalMulticaster.java:55) at ome.system.OmeroContext.publishEvent(OmeroContext.java:327) at ome.system.OmeroContext.publishMessage(OmeroContext.java:341) at ome.services.blitz.impl.AbstractAmdServant.close_async(AbstractAmdServant.java:240) 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 = "Ice.ObjectAdapterDeactivatedException" message = (null) at ome.services.blitz.impl.AbstractAmdServant.close_async(AbstractAmdServant.java:243) ... 11 more 2011-11-10 18:10:17,345 INFO [ ome.services.blitz.Entry] ( main) Calling close on context OMERO.blitz 2011-11-10 18:10:17,346 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Releasing /home/steve/apps/OMERO/OMERO.server-Beta-4.3.3/./lib/scripts 2011-11-10 18:10:17,347 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Releasing /OMERO.data 2011-11-10 18:10:17,356 INFO [ ome.services.blitz.fire.Registry] ( main) Removed ClusterNode/281e364d-4a80-40b8-90b2-a2235801f2c7 from registry 2011-11-10 18:10:17,359 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.executeUpdate - set closed = now() 2011-11-10 18:10:17,359 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@13208327] 2011-11-10 18:10:17,457 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=265(Internal),sess=281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:10:17,471 INFO [ org.perf4j.TimingLogger] ( main) start[1320973817359] time[112] tag[omero.call.success.ome.services.blitz.fire.Ring$3.doWork] 2011-11-10 18:10:17,477 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: 2 2011-11-10 18:10:17,477 INFO [ ome.services.blitz.fire.Ring] ( main) Removed 2 entries for 281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:10:17,477 INFO [ ome.services.blitz.fire.Ring] ( main) Disconnected from OMERO.cluster 2011-11-10 18:10:17,482 INFO [ ome.services.blitz.fire.Registry] ( main) Found 0 cluster node(s) : [] 2011-11-10 18:10:17,482 INFO [e.services.blitz.util.BlitzConfiguration] ( main) Shutting down Ice.Communicator 2011-11-10 18:10:17,492 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 18:10:17,492 INFO [ ome.services.util.ServerVersionCheck] ( main) Stopping OMERO... 2011-11-10 18:10:17,492 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 18:10:17,493 INFO [ ome.services.pixeldata.PixelDataThread] ( main) Shutting down PixelDataThread 2011-11-10 18:10:17,499 INFO [ ome.services.fulltext.FullTextThread] ( main) Shutting down Full-Text Indexer 2011-11-10 18:10:17,500 INFO [.services.scheduler.SchedulerFactoryBean] ( main) Shutting down Quartz Scheduler 2011-11-10 18:10:17,521 INFO [ng.ShutdownSafeEhcacheManagerFactoryBean] ( main) Shutting down EHCache CacheManager 2011-11-10 18:10:17,527 INFO [ ome.services.blitz.Entry] ( main) Finished shutdown. 2011-11-10 18:22:32,928 INFO [ ome.services.blitz.Entry] ( main) Creating OMERO.blitz. Please wait... 2011-11-10 18:22:35,772 INFO [ng.ShutdownSafeEhcacheManagerFactoryBean] ( main) Initializing EHCache CacheManager 2011-11-10 18:22:41,502 INFO [ ome.services.fulltext.FullTextAnalyzer] ( main) Initialized FullTextAnalyzer 2011-11-10 18:22:48,287 INFO [ ome.services.db.DatabaseIdentity] ( main) Using LSID format: urn:lsid:export.openmicroscopy.org:%s:b8b6ae42-3456-496e-a6ae-ca0371744f85_%s%s 2011-11-10 18:22:49,577 INFO [ org.perf4j.TimingLogger] ( main) start[1320974568387] time[1190] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:49,724 INFO [ org.perf4j.TimingLogger] ( main) start[1320974569577] time[147] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:49,840 INFO [ org.perf4j.TimingLogger] ( main) start[1320974569725] time[115] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:49,941 INFO [ org.perf4j.TimingLogger] ( main) start[1320974569840] time[101] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:50,360 INFO [ org.perf4j.TimingLogger] ( main) start[1320974569941] time[419] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:50,461 INFO [ org.perf4j.TimingLogger] ( main) start[1320974570360] time[101] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:50,556 INFO [ org.perf4j.TimingLogger] ( main) start[1320974570461] time[95] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:50,650 INFO [ org.perf4j.TimingLogger] ( main) start[1320974570556] time[94] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:51,394 INFO [ org.perf4j.TimingLogger] ( main) start[1320974570650] time[744] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:51,489 INFO [ org.perf4j.TimingLogger] ( main) start[1320974571394] time[95] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:51,592 INFO [ org.perf4j.TimingLogger] ( main) start[1320974571489] time[103] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:51,696 INFO [ org.perf4j.TimingLogger] ( main) start[1320974571592] time[104] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:51,793 INFO [ org.perf4j.TimingLogger] ( main) start[1320974571696] time[97] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:51,919 INFO [ org.perf4j.TimingLogger] ( main) start[1320974571794] time[125] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:52,101 INFO [ org.perf4j.TimingLogger] ( main) start[1320974571919] time[182] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:52,541 INFO [ org.perf4j.TimingLogger] ( main) start[1320974572101] time[440] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:52,646 INFO [ org.perf4j.TimingLogger] ( main) start[1320974572541] time[105] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:52,771 INFO [ org.perf4j.TimingLogger] ( main) start[1320974572646] time[125] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:52,856 INFO [ org.perf4j.TimingLogger] ( main) start[1320974572772] time[84] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:52,954 INFO [ org.perf4j.TimingLogger] ( main) start[1320974572857] time[97] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:22:52,965 INFO [ ome.io.nio.PixelsService] ( main) PixelsService(path=/OMERO.data, resolver=ome.services.OmeroFilePathResolver@152d950, backoff=ome.io.nio.SimpleBackOff(factor=146.2), sizes=ome.io.nio.ConfiguredTileSizes(w=256,h=256,W=3192,H=3192)) 2011-11-10 18:22:53,259 INFO [ ome.services.fulltext.FullTextThread] ( main) Initializing Full-Text Indexer 2011-11-10 18:22:53,270 INFO [ ome.services.pixeldata.PixelDataThread] ( main) Initializing PixelDataThread (create events only) 2011-11-10 18:22:53,287 INFO [ ome.services.util.DBPatchCheck] ( main) Verified database patch: OMERO4.3__0 2011-11-10 18:22:55,617 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 18:22:55,618 INFO [ ome.services.util.ServerVersionCheck] ( main) OMERO Version: 4.3.3-00d1137e-b2894 Ready. 2011-11-10 18:22:55,618 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 18:22:57,955 INFO [ ome.system.UpgradeCheck] ( main) no update needed 2011-11-10 18:22:57,961 INFO [ ome.tools.hibernate.ExtendedMetadata] ( main) Calculating ExtendedMetadata... 2011-11-10 18:22:58,050 INFO [.services.scheduler.SchedulerFactoryBean] ( main) Starting Quartz Scheduler now 2011-11-10 18:22:58,062 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.util.NamespaceCheck.namespaceCheck 2011-11-10 18:22:58,062 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@15105042] 2011-11-10 18:22:58,341 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=301(Internal),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:22:58,541 INFO [ org.perf4j.TimingLogger] ( main) start[1320974578062] time[479] tag[omero.call.success.ome.services.util.NamespaceCheck$1.doWork] 2011-11-10 18:22:58,542 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: null 2011-11-10 18:22:58,819 INFO [e.services.blitz.util.BlitzConfiguration] ( main) Initializing Ice.Communicator 2011-11-10 18:22:59,500 INFO [ ome.services.blitz.fire.Ring] ( main) Checking cluster 2011-11-10 18:22:59,537 INFO [ ome.services.blitz.fire.Registry] ( main) Found 0 cluster node(s) : [] 2011-11-10 18:22:59,537 INFO [ ome.services.blitz.fire.Ring] ( main) Got 0 cluster uuids : [] 2011-11-10 18:22:59,538 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.getManagerList 2011-11-10 18:22:59,538 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@15105042] 2011-11-10 18:22:59,542 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=null(Internal),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:22:59,560 INFO [ org.perf4j.TimingLogger] ( main) start[1320974579538] time[22] tag[omero.call.success.ome.services.blitz.fire.Ring$2.doWork] 2011-11-10 18:22:59,560 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: (281e364d-4a80-40b8-90b2-a2235801f2c7) 2011-11-10 18:22:59,560 INFO [ ome.services.blitz.fire.Ring] ( main) Purging node: 281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:22:59,605 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.executeUpdate - set closed = now() 2011-11-10 18:22:59,605 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@15105042] 2011-11-10 18:22:59,641 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=302(Internal),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:22:59,655 INFO [ org.perf4j.TimingLogger] ( main) start[1320974579605] time[50] tag[omero.call.success.ome.services.blitz.fire.Ring$3.doWork] 2011-11-10 18:22:59,655 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: 0 2011-11-10 18:22:59,655 INFO [ ome.services.blitz.fire.Ring] ( main) Removed 0 entries with value 281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:22:59,656 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.setManagerDown 2011-11-10 18:22:59,656 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@15105042] 2011-11-10 18:22:59,688 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=303(Internal),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:22:59,696 INFO [ org.perf4j.TimingLogger] ( main) start[1320974579656] time[40] tag[omero.call.success.ome.services.blitz.fire.Ring$4.doWork] 2011-11-10 18:22:59,697 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: 1 2011-11-10 18:22:59,697 INFO [ ome.services.blitz.fire.Ring] ( main) Removed manager: 281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:22:59,697 INFO [ ome.services.blitz.fire.Ring] ( main) handleRingShutdown: 281e364d-4a80-40b8-90b2-a2235801f2c7 2011-11-10 18:22:59,699 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.addManager 2011-11-10 18:22:59,699 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@15105042] 2011-11-10 18:22:59,736 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=304(Internal),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:22:59,742 INFO [ ome.security.basic.CurrentDetails] ( main) Adding log:INSERT,class ome.model.meta.Node,301 2011-11-10 18:22:59,751 INFO [ org.perf4j.TimingLogger] ( main) start[1320974579699] time[52] tag[omero.call.success.ome.services.blitz.fire.Ring$5.doWork] 2011-11-10 18:22:59,751 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: ome.model.meta.Node:Id_301 2011-11-10 18:22:59,756 INFO [ ome.services.blitz.fire.Registry] ( main) Added ClusterNode/7a358153-695e-4817-97ed-2c23532306d8 to registry 2011-11-10 18:22:59,836 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Initializing repository in /OMERO.data 2011-11-10 18:22:59,874 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.scripts.ScriptRepoHelper.loadAll(true) 2011-11-10 18:22:59,874 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@15105042] 2011-11-10 18:22:59,891 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=305(Internal),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:22:59,972 INFO [ org.perf4j.TimingLogger] ( main) start[1320974579874] time[98] tag[omero.call.success.ome.services.scripts.ScriptRepoHelper$5.doWork] 2011-11-10 18:22:59,972 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: (ome.model.core.OriginalFile:Id_1, ome.model.core.OriginalFile:Id_2, ome.model.core.OriginalFile:Id_3, ... 10 more) 2011-11-10 18:22:59,974 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Initializing repository in /home/steve/apps/OMERO/OMERO.server-Beta-4.3.3/./lib/scripts 2011-11-10 18:23:00,088 INFO [ ome.services.util.ServiceHandler] (3-thread-3) Executor.doWork -- ome.services.blitz.repo.ScriptRepositoryI.takeover 2011-11-10 18:23:00,089 INFO [ ome.services.util.ServiceHandler] (3-thread-3) Args: [null, InternalSF@15105042] 2011-11-10 18:23:00,091 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Executor.doWork -- ome.services.blitz.repo.LegacyRepositoryI.takeover 2011-11-10 18:23:00,091 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Args: [null, InternalSF@15105042] 2011-11-10 18:23:00,170 INFO [ ome.services.blitz.Entry] ( main) OMERO.blitz now accepting connections. 2011-11-10 18:23:00,170 INFO [ ome.services.blitz.util.CheckAllJobs] ( Thread-8) Waiting 120 secs. for callbacks 2011-11-10 18:23:00,174 INFO [ ome.security.basic.EventHandler] (3-thread-2) Auth: user=0,group=0,event=306(Internal),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:23:00,183 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-2) Opened repository OMERO.data (uuid=27f05637-0e2a-4b48-aaf5-260e24158d73) 2011-11-10 18:23:00,218 INFO [ ome.security.basic.EventHandler] (3-thread-3) Auth: user=0,group=0,event=307(Internal),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:23:00,227 INFO [ ome.services.blitz.fire.Registry] (3-thread-2) Updated InternalRepository-27f05637-0e2a-4b48-aaf5-260e24158d73 in registry 2011-11-10 18:23:00,231 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-3) Opened repository scripts (uuid=ScriptRepo) 2011-11-10 18:23:00,250 INFO [ ome.services.blitz.fire.Registry] (3-thread-2) Updated PublicRepository-27f05637-0e2a-4b48-aaf5-260e24158d73 in registry 2011-11-10 18:23:00,250 INFO [ ome.services.blitz.fire.Registry] (3-thread-3) Updated InternalRepository-ScriptRepo in registry 2011-11-10 18:23:00,258 INFO [ ome.services.blitz.fire.Registry] (3-thread-3) Updated PublicRepository-ScriptRepo in registry 2011-11-10 18:23:00,260 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-2) Repository now active 2011-11-10 18:23:00,260 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-3) Repository now active 2011-11-10 18:23:00,267 INFO [ org.perf4j.TimingLogger] (3-thread-3) start[1320974580089] time[178] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$GetOrCreateRepo.doWork] 2011-11-10 18:23:00,267 INFO [ ome.services.util.ServiceHandler] (3-thread-3) Rslt: ome.model.core.OriginalFile:Id_14 2011-11-10 18:23:00,268 INFO [ ome.services.util.ServiceHandler] (3-thread-3) Executor.doWork -- ome.services.blitz.repo.ScriptRepositoryI.getDescription(14) 2011-11-10 18:23:00,268 INFO [ ome.services.util.ServiceHandler] (3-thread-3) Args: [null, InternalSF@15105042] 2011-11-10 18:23:00,271 INFO [ org.perf4j.TimingLogger] (3-thread-2) start[1320974580091] time[180] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$GetOrCreateRepo.doWork] 2011-11-10 18:23:00,271 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Rslt: ome.model.core.OriginalFile:Id_15 2011-11-10 18:23:00,271 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Executor.doWork -- ome.services.blitz.repo.LegacyRepositoryI.getDescription(15) 2011-11-10 18:23:00,271 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Args: [null, InternalSF@15105042] 2011-11-10 18:23:00,272 INFO [ ome.security.basic.EventHandler] (3-thread-3) Auth: user=0,group=0,event=null(Internal),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:23:00,273 INFO [ ome.security.basic.EventHandler] (3-thread-2) Auth: user=0,group=0,event=null(Internal),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:23:00,288 INFO [ org.perf4j.TimingLogger] (3-thread-2) start[1320974580272] time[16] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$1.doWork] 2011-11-10 18:23:00,289 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Rslt: ome.model.core.OriginalFile:Id_15 2011-11-10 18:23:00,291 INFO [ org.perf4j.TimingLogger] (3-thread-3) start[1320974580269] time[22] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$1.doWork] 2011-11-10 18:23:00,291 INFO [ ome.services.util.ServiceHandler] (3-thread-3) Rslt: ome.model.core.OriginalFile:Id_14 2011-11-10 18:23:02,535 INFO [ ome.services.util.ServiceHandler] (l.Server-8) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 18:23:02,536 INFO [ ome.services.util.ServiceHandler] (l.Server-8) Args: [null, InternalSF@15105042] 2011-11-10 18:23:02,562 INFO [ ome.security.basic.EventHandler] (l.Server-8) Auth: user=0,group=0,event=308(Sessions),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:23:02,601 INFO [ ome.security.basic.CurrentDetails] (l.Server-8) Adding log:INSERT,class ome.model.meta.Session,1023 2011-11-10 18:23:02,643 INFO [ org.perf4j.TimingLogger] (l.Server-8) start[1320974582536] time[107] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 18:23:02,643 INFO [ ome.services.util.ServiceHandler] (l.Server-8) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:23:02,656 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-8) Created session ServiceFactoryI(session-9c3c6d9d-a84b-4003-8ab4-8f89bba462a3/0fe4a7b4-0dff-4fe2-b105-7aea64c3840b) for user root (agent=Python service) 2011-11-10 18:23:02,684 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-0) Added servant to adapter: 0fe4a7b4-0dff-4fe2-b105-7aea64c3840b/9c3c6d9d-a84b-4003-8ab4-8f89bba462a3omero.api.IConfig(omero.api._IConfigTie@a5d82a) 2011-11-10 18:23:02,699 INFO [ ome.services.util.ServiceHandler] (l.Server-1) Meth: interface ome.api.IConfig.getConfigValue 2011-11-10 18:23:02,700 INFO [ ome.services.util.ServiceHandler] (l.Server-1) Args: [omero.data.dir] 2011-11-10 18:23:02,729 INFO [ ome.security.basic.EventHandler] (l.Server-1) Auth: user=0,group=0,event=309(User),sess=0fe4a7b4-0dff-4fe2-b105-7aea64c3840b 2011-11-10 18:23:02,734 INFO [ org.perf4j.TimingLogger] (l.Server-1) start[1320974582700] time[34] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue] 2011-11-10 18:23:02,734 INFO [ ome.services.util.ServiceHandler] (l.Server-1) Rslt: /OMERO.data 2011-11-10 18:23:02,737 INFO [e.services.sessions.SessionContext$Count] (l.Server-3) -Reference count: 0fe4a7b4-0dff-4fe2-b105-7aea64c3840b=0 2011-11-10 18:23:02,737 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-3) doDestroy(ServiceFactoryI(session-9c3c6d9d-a84b-4003-8ab4-8f89bba462a3/0fe4a7b4-0dff-4fe2-b105-7aea64c3840b)) 2011-11-10 18:23:02,738 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-3) Unregistered servant:0fe4a7b4-0dff-4fe2-b105-7aea64c3840b/9c3c6d9d-a84b-4003-8ab4-8f89bba462a3omero.api.IConfig(omero.api._IConfigTie@a5d82a) 2011-11-10 18:23:02,738 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-3) Removed servant from adapter: 9c3c6d9d-a84b-4003-8ab4-8f89bba462a3omero.api.IConfig 2011-11-10 18:23:02,738 INFO [ome.services.sessions.SessionManagerImpl] (l.Server-3) closeSession called and no more references: 0fe4a7b4-0dff-4fe2-b105-7aea64c3840b 2011-11-10 18:23:02,738 INFO [ome.services.sessions.state.SessionCache] (l.Server-3) Destroying session 0fe4a7b4-0dff-4fe2-b105-7aea64c3840b due to : Remove session called 2011-11-10 18:23:02,738 INFO [ org.perf4j.TimingLogger] (l.Server-3) start[1320974582646] time[92] tag[omero.session] 2011-11-10 18:23:02,742 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-3) Reaping 1 clients for 0fe4a7b4-0dff-4fe2-b105-7aea64c3840b 2011-11-10 18:23:09,526 INFO [ ome.services.util.ServiceHandler] (l.Server-4) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 18:23:09,526 INFO [ ome.services.util.ServiceHandler] (l.Server-4) Args: [null, InternalSF@15105042] 2011-11-10 18:23:09,530 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 18:23:09,530 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Args: [null, InternalSF@15105042] 2011-11-10 18:23:09,548 INFO [ ome.security.basic.EventHandler] (l.Server-4) Auth: user=0,group=0,event=310(Sessions),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:23:09,559 INFO [ ome.security.basic.EventHandler] (l.Server-2) Auth: user=0,group=0,event=311(Sessions),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:23:09,567 INFO [ ome.security.basic.CurrentDetails] (l.Server-4) Adding log:INSERT,class ome.model.meta.Session,1024 2011-11-10 18:23:09,585 INFO [ ome.security.basic.CurrentDetails] (l.Server-2) Adding log:INSERT,class ome.model.meta.Session,1025 2011-11-10 18:23:09,585 INFO [ org.perf4j.TimingLogger] (l.Server-4) start[1320974589526] time[59] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 18:23:09,585 INFO [ ome.services.util.ServiceHandler] (l.Server-4) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:23:09,587 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-4) Created session ServiceFactoryI(session-3353c7d5-e141-4b9c-a025-7a132de72954/18ae5f46-e4fb-4dae-92e1-aaa1518a50d0) for user root (agent=Python service) 2011-11-10 18:23:09,592 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-8) Added servant to adapter: 18ae5f46-e4fb-4dae-92e1-aaa1518a50d0/3353c7d5-e141-4b9c-a025-7a132de72954omero.api.IConfig(omero.api._IConfigTie@11f6413) 2011-11-10 18:23:09,593 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Meth: interface ome.api.IConfig.getConfigValue 2011-11-10 18:23:09,593 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Args: [omero.data.dir] 2011-11-10 18:23:09,612 INFO [ org.perf4j.TimingLogger] (l.Server-2) start[1320974589530] time[82] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 18:23:09,612 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:23:09,613 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-2) Created session ServiceFactoryI(session-d023f84b-00df-47cf-b6bf-ee08ebed848c/4559ffcc-d7b5-4808-833b-9650cc9aa000) for user root (agent=Python service) 2011-11-10 18:23:09,614 INFO [ ome.security.basic.EventHandler] (l.Server-0) Auth: user=0,group=0,event=312(User),sess=18ae5f46-e4fb-4dae-92e1-aaa1518a50d0 2011-11-10 18:23:09,621 INFO [ org.perf4j.TimingLogger] (l.Server-0) start[1320974589593] time[28] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue] 2011-11-10 18:23:09,621 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Rslt: /OMERO.data 2011-11-10 18:23:09,623 INFO [ ome.services.blitz.util.CheckAllJobs] (l.Server-1) Received 0 job(s) 2011-11-10 18:23:09,626 INFO [ ome.services.util.ServiceHandler] (l.Server-9) Meth: interface ome.api.IConfig.getDatabaseUuid 2011-11-10 18:23:09,626 INFO [ ome.services.util.ServiceHandler] (l.Server-9) Args: () 2011-11-10 18:23:09,639 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-4) Added servant to adapter: 4559ffcc-d7b5-4808-833b-9650cc9aa000/d023f84b-00df-47cf-b6bf-ee08ebed848comero.grid.SharedResources(omero.grid._SharedResourcesTie@1d0f745) 2011-11-10 18:23:09,655 INFO [ ome.security.basic.EventHandler] (l.Server-9) Auth: user=0,group=0,event=313(User),sess=18ae5f46-e4fb-4dae-92e1-aaa1518a50d0 2011-11-10 18:23:09,660 INFO [ org.perf4j.TimingLogger] (l.Server-9) start[1320974589626] time[34] tag[omero.call.success.ome.logic.ConfigImpl.getDatabaseUuid] 2011-11-10 18:23:09,660 INFO [ ome.services.util.ServiceHandler] (l.Server-9) Rslt: b8b6ae42-3456-496e-a6ae-ca0371744f85 2011-11-10 18:23:09,722 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-3) Added servant to adapter: 18ae5f46-e4fb-4dae-92e1-aaa1518a50d0/3353c7d5-e141-4b9c-a025-7a132de72954omero.api.IQuery(omero.api._IQueryTie@1bbe4e1) 2011-11-10 18:23:09,734 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Meth: interface ome.api.IQuery.findByQuery 2011-11-10 18:23:09,735 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Args: [select f from OriginalFile f where sha1 = :uuid, PARAMS:uuid=27f05637-0e2a-4b48-aaf5-260e24158d73 ] 2011-11-10 18:23:09,737 INFO [ ome.security.basic.EventHandler] (l.Server-5) Auth: user=0,group=0,event=null(User),sess=18ae5f46-e4fb-4dae-92e1-aaa1518a50d0 2011-11-10 18:23:09,745 INFO [ org.perf4j.TimingLogger] (l.Server-5) start[1320974589735] time[10] tag[omero.call.success.ome.logic.QueryImpl.findByQuery] 2011-11-10 18:23:09,745 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Rslt: ome.model.core.OriginalFile:Id_15 2011-11-10 18:24:00,011 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-1) Performing requestHeartbeats 2011-11-10 18:27:00,022 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-5) Performing requestHeartbeats 2011-11-10 18:30:00,022 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-2) Performing requestHeartbeats 2011-11-10 18:30:13,018 INFO [ ome.services.blitz.fire.Ring] (3-thread-4) Checking cluster 2011-11-10 18:30:13,046 INFO [ ome.services.blitz.fire.Registry] (3-thread-4) Found 1 cluster node(s) : [ClusterNode/7a358153-695e-4817-97ed-2c23532306d8 -t:tcp -h 129.128.191.25 -p 41297] 2011-11-10 18:30:13,050 INFO [ ome.services.blitz.fire.Ring] (3-thread-4) Got 1 cluster uuids : [7a358153-695e-4817-97ed-2c23532306d8] 2011-11-10 18:30:13,051 INFO [ ome.services.util.ServiceHandler] (3-thread-4) Executor.doWork -- ome.services.blitz.fire.Ring.getManagerList 2011-11-10 18:30:13,051 INFO [ ome.services.util.ServiceHandler] (3-thread-4) Args: [null, InternalSF@15105042] 2011-11-10 18:30:13,101 INFO [ ome.security.basic.EventHandler] (3-thread-4) Auth: user=0,group=0,event=null(Internal),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:30:13,115 INFO [ org.perf4j.TimingLogger] (3-thread-4) start[1320975013051] time[64] tag[omero.call.success.ome.services.blitz.fire.Ring$2.doWork] 2011-11-10 18:30:13,115 INFO [ ome.services.util.ServiceHandler] (3-thread-4) Rslt: (7a358153-695e-4817-97ed-2c23532306d8) 2011-11-10 18:33:00,077 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-2) Performing requestHeartbeats 2011-11-10 18:33:11,239 INFO [ ome.services.blitz.Entry] ( main) Calling close on context OMERO.blitz 2011-11-10 18:33:11,241 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Releasing /home/steve/apps/OMERO/OMERO.server-Beta-4.3.3/./lib/scripts 2011-11-10 18:33:11,458 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Releasing /OMERO.data 2011-11-10 18:33:11,557 INFO [ ome.services.blitz.fire.Registry] ( main) Removed ClusterNode/7a358153-695e-4817-97ed-2c23532306d8 from registry 2011-11-10 18:33:11,558 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.executeUpdate - set closed = now() 2011-11-10 18:33:11,558 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@15105042] 2011-11-10 18:33:12,698 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=314(Internal),sess=7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:33:12,839 INFO [ org.perf4j.TimingLogger] ( main) start[1320975191558] time[1281] tag[omero.call.success.ome.services.blitz.fire.Ring$3.doWork] 2011-11-10 18:33:12,840 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: 2 2011-11-10 18:33:12,840 INFO [ ome.services.blitz.fire.Ring] ( main) Removed 2 entries for 7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:33:12,842 INFO [ ome.services.blitz.fire.Ring] ( main) Disconnected from OMERO.cluster 2011-11-10 18:33:12,845 INFO [ ome.services.blitz.fire.Registry] ( main) Found 0 cluster node(s) : [] 2011-11-10 18:33:12,846 INFO [e.services.blitz.util.BlitzConfiguration] ( main) Shutting down Ice.Communicator 2011-11-10 18:33:12,867 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 18:33:12,867 INFO [ ome.services.util.ServerVersionCheck] ( main) Stopping OMERO... 2011-11-10 18:33:12,884 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 18:33:12,884 INFO [ ome.services.pixeldata.PixelDataThread] ( main) Shutting down PixelDataThread 2011-11-10 18:33:12,885 INFO [ ome.services.fulltext.FullTextThread] ( main) Shutting down Full-Text Indexer 2011-11-10 18:33:12,886 INFO [.services.scheduler.SchedulerFactoryBean] ( main) Shutting down Quartz Scheduler 2011-11-10 18:33:12,912 INFO [ng.ShutdownSafeEhcacheManagerFactoryBean] ( main) Shutting down EHCache CacheManager 2011-11-10 18:33:12,913 INFO [ ome.services.blitz.Entry] ( main) Finished shutdown. 2011-11-10 18:33:28,012 INFO [ ome.services.blitz.Entry] ( main) Creating OMERO.blitz. Please wait... 2011-11-10 18:33:30,576 INFO [ng.ShutdownSafeEhcacheManagerFactoryBean] ( main) Initializing EHCache CacheManager 2011-11-10 18:33:36,745 INFO [ ome.services.fulltext.FullTextAnalyzer] ( main) Initialized FullTextAnalyzer 2011-11-10 18:33:44,931 INFO [ ome.services.db.DatabaseIdentity] ( main) Using LSID format: urn:lsid:export.openmicroscopy.org:%s:b8b6ae42-3456-496e-a6ae-ca0371744f85_%s%s 2011-11-10 18:33:46,220 INFO [ org.perf4j.TimingLogger] ( main) start[1320975225318] time[902] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:46,428 INFO [ org.perf4j.TimingLogger] ( main) start[1320975226221] time[207] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:46,615 INFO [ org.perf4j.TimingLogger] ( main) start[1320975226429] time[186] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:46,934 INFO [ org.perf4j.TimingLogger] ( main) start[1320975226615] time[319] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:47,075 INFO [ org.perf4j.TimingLogger] ( main) start[1320975226934] time[141] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:47,189 INFO [ org.perf4j.TimingLogger] ( main) start[1320975227075] time[114] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:47,314 INFO [ org.perf4j.TimingLogger] ( main) start[1320975227190] time[124] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:48,436 INFO [ org.perf4j.TimingLogger] ( main) start[1320975227315] time[1121] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:48,547 INFO [ org.perf4j.TimingLogger] ( main) start[1320975228436] time[111] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:48,681 INFO [ org.perf4j.TimingLogger] ( main) start[1320975228547] time[134] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:48,798 INFO [ org.perf4j.TimingLogger] ( main) start[1320975228681] time[117] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:48,909 INFO [ org.perf4j.TimingLogger] ( main) start[1320975228798] time[111] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:49,154 INFO [ org.perf4j.TimingLogger] ( main) start[1320975228909] time[245] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:49,455 INFO [ org.perf4j.TimingLogger] ( main) start[1320975229155] time[300] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:49,597 INFO [ org.perf4j.TimingLogger] ( main) start[1320975229455] time[142] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:49,725 INFO [ org.perf4j.TimingLogger] ( main) start[1320975229597] time[128] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:49,832 INFO [ org.perf4j.TimingLogger] ( main) start[1320975229725] time[107] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:49,933 INFO [ org.perf4j.TimingLogger] ( main) start[1320975229832] time[101] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:50,072 INFO [ org.perf4j.TimingLogger] ( main) start[1320975229933] time[139] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:51,090 INFO [ org.perf4j.TimingLogger] ( main) start[1320975230072] time[1018] tag[ome.io.nio.SimpleBackOff.256X256] 2011-11-10 18:33:51,108 INFO [ ome.io.nio.PixelsService] ( main) PixelsService(path=/OMERO.data, resolver=ome.services.OmeroFilePathResolver@788b76, backoff=ome.io.nio.SimpleBackOff(factor=240.8), sizes=ome.io.nio.ConfiguredTileSizes(w=256,h=256,W=3192,H=3192)) 2011-11-10 18:33:51,438 INFO [ ome.services.fulltext.FullTextThread] ( main) Initializing Full-Text Indexer 2011-11-10 18:33:51,449 INFO [ ome.services.pixeldata.PixelDataThread] ( main) Initializing PixelDataThread (create events only) 2011-11-10 18:33:51,472 INFO [ ome.services.util.DBPatchCheck] ( main) Verified database patch: OMERO4.3__0 2011-11-10 18:33:52,464 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 18:33:52,465 INFO [ ome.services.util.ServerVersionCheck] ( main) OMERO Version: 4.3.3-00d1137e-b2894 Ready. 2011-11-10 18:33:52,465 INFO [ ome.services.util.ServerVersionCheck] ( main) ------------------------------------------------- 2011-11-10 18:33:54,721 INFO [ ome.system.UpgradeCheck] ( main) no update needed 2011-11-10 18:33:54,727 INFO [ ome.tools.hibernate.ExtendedMetadata] ( main) Calculating ExtendedMetadata... 2011-11-10 18:33:54,812 INFO [.services.scheduler.SchedulerFactoryBean] ( main) Starting Quartz Scheduler now 2011-11-10 18:33:54,820 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.util.NamespaceCheck.namespaceCheck 2011-11-10 18:33:54,821 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@11104210] 2011-11-10 18:33:55,457 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=351(Internal),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:33:55,712 INFO [ org.perf4j.TimingLogger] ( main) start[1320975234821] time[891] tag[omero.call.success.ome.services.util.NamespaceCheck$1.doWork] 2011-11-10 18:33:55,713 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: null 2011-11-10 18:33:56,144 INFO [e.services.blitz.util.BlitzConfiguration] ( main) Initializing Ice.Communicator 2011-11-10 18:33:57,101 INFO [ ome.services.blitz.fire.Ring] ( main) Checking cluster 2011-11-10 18:33:57,168 INFO [ ome.services.blitz.fire.Registry] ( main) Found 0 cluster node(s) : [] 2011-11-10 18:33:57,169 INFO [ ome.services.blitz.fire.Ring] ( main) Got 0 cluster uuids : [] 2011-11-10 18:33:57,170 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.getManagerList 2011-11-10 18:33:57,170 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@11104210] 2011-11-10 18:33:57,175 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=null(Internal),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:33:57,209 INFO [ org.perf4j.TimingLogger] ( main) start[1320975237170] time[39] tag[omero.call.success.ome.services.blitz.fire.Ring$2.doWork] 2011-11-10 18:33:57,209 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: (7a358153-695e-4817-97ed-2c23532306d8) 2011-11-10 18:33:57,210 INFO [ ome.services.blitz.fire.Ring] ( main) Purging node: 7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:33:57,300 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.executeUpdate - set closed = now() 2011-11-10 18:33:57,300 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@11104210] 2011-11-10 18:33:57,328 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=352(Internal),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:33:57,337 INFO [ org.perf4j.TimingLogger] ( main) start[1320975237300] time[37] tag[omero.call.success.ome.services.blitz.fire.Ring$3.doWork] 2011-11-10 18:33:57,338 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: 0 2011-11-10 18:33:57,338 INFO [ ome.services.blitz.fire.Ring] ( main) Removed 0 entries with value 7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:33:57,339 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.setManagerDown 2011-11-10 18:33:57,339 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@11104210] 2011-11-10 18:33:57,359 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=353(Internal),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:33:57,365 INFO [ org.perf4j.TimingLogger] ( main) start[1320975237339] time[25] tag[omero.call.success.ome.services.blitz.fire.Ring$4.doWork] 2011-11-10 18:33:57,365 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: 1 2011-11-10 18:33:57,365 INFO [ ome.services.blitz.fire.Ring] ( main) Removed manager: 7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:33:57,365 INFO [ ome.services.blitz.fire.Ring] ( main) handleRingShutdown: 7a358153-695e-4817-97ed-2c23532306d8 2011-11-10 18:33:57,366 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.addManager 2011-11-10 18:33:57,366 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@11104210] 2011-11-10 18:33:57,393 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=354(Internal),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:33:57,400 INFO [ ome.security.basic.CurrentDetails] ( main) Adding log:INSERT,class ome.model.meta.Node,351 2011-11-10 18:33:57,409 INFO [ org.perf4j.TimingLogger] ( main) start[1320975237366] time[43] tag[omero.call.success.ome.services.blitz.fire.Ring$5.doWork] 2011-11-10 18:33:57,409 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: ome.model.meta.Node:Id_351 2011-11-10 18:33:57,414 INFO [ ome.services.blitz.fire.Registry] ( main) Added ClusterNode/a54103c5-e98f-4765-b536-cbd5fa8b946f to registry 2011-11-10 18:33:57,449 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Initializing repository in /OMERO.data 2011-11-10 18:33:57,504 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.scripts.ScriptRepoHelper.loadAll(true) 2011-11-10 18:33:57,504 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@11104210] 2011-11-10 18:33:57,532 INFO [ ome.security.basic.EventHandler] ( main) Auth: user=0,group=0,event=355(Internal),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:33:57,678 INFO [ org.perf4j.TimingLogger] ( main) start[1320975237504] time[174] tag[omero.call.success.ome.services.scripts.ScriptRepoHelper$5.doWork] 2011-11-10 18:33:57,679 INFO [ ome.services.util.ServiceHandler] ( main) Rslt: (ome.model.core.OriginalFile:Id_1, ome.model.core.OriginalFile:Id_2, ome.model.core.OriginalFile:Id_3, ... 10 more) 2011-11-10 18:33:57,679 INFO [.services.blitz.repo.AbstractRepositoryI] ( main) Initializing repository in /home/steve/apps/OMERO/OMERO.server-Beta-4.3.3/./lib/scripts 2011-11-10 18:33:57,765 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Executor.doWork -- ome.services.blitz.repo.LegacyRepositoryI.takeover 2011-11-10 18:33:57,765 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Args: [null, InternalSF@11104210] 2011-11-10 18:33:57,768 INFO [ ome.services.util.ServiceHandler] (3-thread-3) Executor.doWork -- ome.services.blitz.repo.ScriptRepositoryI.takeover 2011-11-10 18:33:57,768 INFO [ ome.services.util.ServiceHandler] (3-thread-3) Args: [null, InternalSF@11104210] 2011-11-10 18:33:57,816 INFO [ ome.security.basic.EventHandler] (3-thread-2) Auth: user=0,group=0,event=356(Internal),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:33:57,833 INFO [ ome.services.blitz.util.CheckAllJobs] ( Thread-8) Waiting 120 secs. for callbacks 2011-11-10 18:33:57,834 INFO [ ome.services.blitz.Entry] ( main) OMERO.blitz now accepting connections. 2011-11-10 18:33:57,841 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-2) Opened repository OMERO.data (uuid=27f05637-0e2a-4b48-aaf5-260e24158d73) 2011-11-10 18:33:57,892 INFO [ ome.services.blitz.fire.Registry] (3-thread-2) Updated InternalRepository-27f05637-0e2a-4b48-aaf5-260e24158d73 in registry 2011-11-10 18:33:57,896 INFO [ ome.services.blitz.fire.Registry] (3-thread-2) Updated PublicRepository-27f05637-0e2a-4b48-aaf5-260e24158d73 in registry 2011-11-10 18:33:57,908 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-2) Repository now active 2011-11-10 18:33:57,915 INFO [ ome.security.basic.EventHandler] (3-thread-3) Auth: user=0,group=0,event=357(Internal),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:33:57,921 INFO [ org.perf4j.TimingLogger] (3-thread-2) start[1320975237765] time[156] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$GetOrCreateRepo.doWork] 2011-11-10 18:33:57,921 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Rslt: ome.model.core.OriginalFile:Id_15 2011-11-10 18:33:57,922 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Executor.doWork -- ome.services.blitz.repo.LegacyRepositoryI.getDescription(15) 2011-11-10 18:33:57,922 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Args: [null, InternalSF@11104210] 2011-11-10 18:33:57,924 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-3) Opened repository scripts (uuid=ScriptRepo) 2011-11-10 18:33:57,924 INFO [ ome.security.basic.EventHandler] (3-thread-2) Auth: user=0,group=0,event=null(Internal),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:33:57,927 INFO [ ome.services.blitz.fire.Registry] (3-thread-3) Updated InternalRepository-ScriptRepo in registry 2011-11-10 18:33:57,931 INFO [ ome.services.blitz.fire.Registry] (3-thread-3) Updated PublicRepository-ScriptRepo in registry 2011-11-10 18:33:57,932 INFO [.services.blitz.repo.AbstractRepositoryI] (3-thread-3) Repository now active 2011-11-10 18:33:57,936 INFO [ org.perf4j.TimingLogger] (3-thread-3) start[1320975237768] time[168] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$GetOrCreateRepo.doWork] 2011-11-10 18:33:57,936 INFO [ ome.services.util.ServiceHandler] (3-thread-3) Rslt: ome.model.core.OriginalFile:Id_14 2011-11-10 18:33:57,936 INFO [ ome.services.util.ServiceHandler] (3-thread-3) Executor.doWork -- ome.services.blitz.repo.ScriptRepositoryI.getDescription(14) 2011-11-10 18:33:57,936 INFO [ ome.services.util.ServiceHandler] (3-thread-3) Args: [null, InternalSF@11104210] 2011-11-10 18:33:57,938 INFO [ ome.security.basic.EventHandler] (3-thread-3) Auth: user=0,group=0,event=null(Internal),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:33:57,943 INFO [ org.perf4j.TimingLogger] (3-thread-2) start[1320975237922] time[21] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$1.doWork] 2011-11-10 18:33:57,943 INFO [ ome.services.util.ServiceHandler] (3-thread-2) Rslt: ome.model.core.OriginalFile:Id_15 2011-11-10 18:33:57,952 INFO [ org.perf4j.TimingLogger] (3-thread-3) start[1320975237936] time[16] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$1.doWork] 2011-11-10 18:33:57,952 INFO [ ome.services.util.ServiceHandler] (3-thread-3) Rslt: ome.model.core.OriginalFile:Id_14 2011-11-10 18:34:00,162 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 18:34:00,162 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Args: [null, InternalSF@11104210] 2011-11-10 18:34:00,194 INFO [ ome.security.basic.EventHandler] (l.Server-0) Auth: user=0,group=0,event=358(Sessions),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:34:00,235 INFO [ ome.security.basic.CurrentDetails] (l.Server-0) Adding log:INSERT,class ome.model.meta.Session,1176 2011-11-10 18:34:00,271 INFO [ org.perf4j.TimingLogger] (l.Server-0) start[1320975240162] time[109] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 18:34:00,271 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:34:00,285 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-0) Created session ServiceFactoryI(session-3bc373fc-2117-4efa-bbc6-33db40f6831b/66fc2b5d-c28f-4c21-91bf-d6b2956ca12a) for user root (agent=Python service) 2011-11-10 18:34:00,318 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-1) Added servant to adapter: 66fc2b5d-c28f-4c21-91bf-d6b2956ca12a/3bc373fc-2117-4efa-bbc6-33db40f6831bomero.api.IConfig(omero.api._IConfigTie@a5d82a) 2011-11-10 18:34:00,330 INFO [ ome.services.util.ServiceHandler] (l.Server-4) Meth: interface ome.api.IConfig.getConfigValue 2011-11-10 18:34:00,331 INFO [ ome.services.util.ServiceHandler] (l.Server-4) Args: [omero.data.dir] 2011-11-10 18:34:00,348 INFO [ ome.security.basic.EventHandler] (l.Server-4) Auth: user=0,group=0,event=359(User),sess=66fc2b5d-c28f-4c21-91bf-d6b2956ca12a 2011-11-10 18:34:00,354 INFO [ org.perf4j.TimingLogger] (l.Server-4) start[1320975240331] time[23] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue] 2011-11-10 18:34:00,354 INFO [ ome.services.util.ServiceHandler] (l.Server-4) Rslt: /OMERO.data 2011-11-10 18:34:00,358 INFO [e.services.sessions.SessionContext$Count] (l.Server-8) -Reference count: 66fc2b5d-c28f-4c21-91bf-d6b2956ca12a=0 2011-11-10 18:34:00,358 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-8) doDestroy(ServiceFactoryI(session-3bc373fc-2117-4efa-bbc6-33db40f6831b/66fc2b5d-c28f-4c21-91bf-d6b2956ca12a)) 2011-11-10 18:34:00,359 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-8) Unregistered servant:66fc2b5d-c28f-4c21-91bf-d6b2956ca12a/3bc373fc-2117-4efa-bbc6-33db40f6831bomero.api.IConfig(omero.api._IConfigTie@a5d82a) 2011-11-10 18:34:00,359 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-8) Removed servant from adapter: 3bc373fc-2117-4efa-bbc6-33db40f6831bomero.api.IConfig 2011-11-10 18:34:00,359 INFO [ome.services.sessions.SessionManagerImpl] (l.Server-8) closeSession called and no more references: 66fc2b5d-c28f-4c21-91bf-d6b2956ca12a 2011-11-10 18:34:00,359 INFO [ome.services.sessions.state.SessionCache] (l.Server-8) Destroying session 66fc2b5d-c28f-4c21-91bf-d6b2956ca12a due to : Remove session called 2011-11-10 18:34:00,359 INFO [ org.perf4j.TimingLogger] (l.Server-8) start[1320975240275] time[84] tag[omero.session] 2011-11-10 18:34:00,362 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-8) Reaping 1 clients for 66fc2b5d-c28f-4c21-91bf-d6b2956ca12a 2011-11-10 18:34:07,155 INFO [ ome.services.util.ServiceHandler] (l.Server-9) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 18:34:07,156 INFO [ ome.services.util.ServiceHandler] (l.Server-9) Args: [null, InternalSF@11104210] 2011-11-10 18:34:07,160 INFO [ ome.services.util.ServiceHandler] (l.Server-3) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 18:34:07,160 INFO [ ome.services.util.ServiceHandler] (l.Server-3) Args: [null, InternalSF@11104210] 2011-11-10 18:34:07,183 INFO [ ome.security.basic.EventHandler] (l.Server-9) Auth: user=0,group=0,event=360(Sessions),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:34:07,193 INFO [ ome.security.basic.EventHandler] (l.Server-3) Auth: user=0,group=0,event=361(Sessions),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:34:07,212 INFO [ ome.security.basic.CurrentDetails] (l.Server-9) Adding log:INSERT,class ome.model.meta.Session,1177 2011-11-10 18:34:07,223 INFO [ ome.security.basic.CurrentDetails] (l.Server-3) Adding log:INSERT,class ome.model.meta.Session,1178 2011-11-10 18:34:07,232 INFO [ org.perf4j.TimingLogger] (l.Server-9) start[1320975247156] time[76] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 18:34:07,233 INFO [ ome.services.util.ServiceHandler] (l.Server-9) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:34:07,239 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-9) Created session ServiceFactoryI(session-e7befe89-4e6d-41d5-ba83-c3c2d41f2423/1dd55fc1-83ac-42e4-aca6-270e42c584bb) for user root (agent=Python service) 2011-11-10 18:34:07,250 INFO [ ome.services.blitz.util.CheckAllJobs] (l.Server-7) Received 0 job(s) 2011-11-10 18:34:07,257 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-1) Added servant to adapter: 1dd55fc1-83ac-42e4-aca6-270e42c584bb/e7befe89-4e6d-41d5-ba83-c3c2d41f2423omero.grid.SharedResources(omero.grid._SharedResourcesTie@1a3954) 2011-11-10 18:34:07,284 INFO [ org.perf4j.TimingLogger] (l.Server-3) start[1320975247160] time[124] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 18:34:07,285 INFO [ ome.services.util.ServiceHandler] (l.Server-3) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:34:07,285 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-3) Created session ServiceFactoryI(session-3be608b0-7fb5-45b5-969a-99390a80773a/2489f8de-0fc8-408d-9122-9ee94ec619be) for user root (agent=Python service) 2011-11-10 18:34:07,290 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-2) Added servant to adapter: 2489f8de-0fc8-408d-9122-9ee94ec619be/3be608b0-7fb5-45b5-969a-99390a80773aomero.api.IConfig(omero.api._IConfigTie@847c91) 2011-11-10 18:34:07,291 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Meth: interface ome.api.IConfig.getConfigValue 2011-11-10 18:34:07,291 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Args: [omero.data.dir] 2011-11-10 18:34:07,308 INFO [ ome.security.basic.EventHandler] (l.Server-0) Auth: user=0,group=0,event=362(User),sess=2489f8de-0fc8-408d-9122-9ee94ec619be 2011-11-10 18:34:07,315 INFO [ org.perf4j.TimingLogger] (l.Server-0) start[1320975247291] time[24] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue] 2011-11-10 18:34:07,315 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Rslt: /OMERO.data 2011-11-10 18:34:07,319 INFO [ ome.services.util.ServiceHandler] (l.Server-7) Meth: interface ome.api.IConfig.getDatabaseUuid 2011-11-10 18:34:07,319 INFO [ ome.services.util.ServiceHandler] (l.Server-7) Args: () 2011-11-10 18:34:07,338 INFO [ ome.security.basic.EventHandler] (l.Server-7) Auth: user=0,group=0,event=363(User),sess=2489f8de-0fc8-408d-9122-9ee94ec619be 2011-11-10 18:34:07,342 INFO [ org.perf4j.TimingLogger] (l.Server-7) start[1320975247319] time[23] tag[omero.call.success.ome.logic.ConfigImpl.getDatabaseUuid] 2011-11-10 18:34:07,342 INFO [ ome.services.util.ServiceHandler] (l.Server-7) Rslt: b8b6ae42-3456-496e-a6ae-ca0371744f85 2011-11-10 18:34:07,369 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-4) Added servant to adapter: 2489f8de-0fc8-408d-9122-9ee94ec619be/3be608b0-7fb5-45b5-969a-99390a80773aomero.api.IQuery(omero.api._IQueryTie@5a384a) 2011-11-10 18:34:07,379 INFO [ ome.services.util.ServiceHandler] (l.Server-8) Meth: interface ome.api.IQuery.findByQuery 2011-11-10 18:34:07,379 INFO [ ome.services.util.ServiceHandler] (l.Server-8) Args: [select f from OriginalFile f where sha1 = :uuid, PARAMS:uuid=27f05637-0e2a-4b48-aaf5-260e24158d73 ] 2011-11-10 18:34:07,380 INFO [ ome.security.basic.EventHandler] (l.Server-8) Auth: user=0,group=0,event=null(User),sess=2489f8de-0fc8-408d-9122-9ee94ec619be 2011-11-10 18:34:07,387 INFO [ org.perf4j.TimingLogger] (l.Server-8) start[1320975247379] time[8] tag[omero.call.success.ome.logic.QueryImpl.findByQuery] 2011-11-10 18:34:07,387 INFO [ ome.services.util.ServiceHandler] (l.Server-8) Rslt: ome.model.core.OriginalFile:Id_15 2011-11-10 18:34:15,009 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Executor.doWork -- ome.services.sessions.SessionManagerImpl.executeCheckPasswordRO(root) 2011-11-10 18:34:15,009 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Args: [null, InternalSF@11104210] 2011-11-10 18:34:15,010 INFO [ ome.security.basic.EventHandler] (l.Server-5) Auth: user=0,group=0,event=null(Sessions),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:34:15,020 INFO [ org.perf4j.TimingLogger] (l.Server-5) start[1320975255009] time[11] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$8.doWork] 2011-11-10 18:34:15,020 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Rslt: true 2011-11-10 18:34:15,049 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession 2011-11-10 18:34:15,049 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Args: [null, InternalSF@11104210] 2011-11-10 18:34:15,079 INFO [ ome.security.basic.EventHandler] (l.Server-0) Auth: user=0,group=0,event=364(Sessions),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:34:15,094 INFO [ ome.security.basic.CurrentDetails] (l.Server-0) Adding log:INSERT,class ome.model.meta.Session,1179 2011-11-10 18:34:15,107 INFO [ org.perf4j.TimingLogger] (l.Server-0) start[1320975255049] time[58] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork] 2011-11-10 18:34:15,108 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:34:15,135 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-0) Created session ServiceFactoryI(session-a99276f8-2570-4e18-93bd-f94e76c1606b/89e90972-ff11-45bf-b9b1-b768b54459c9) for user root (agent=OMERO.java) 2011-11-10 18:34:15,208 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-9) Added servant to adapter: 89e90972-ff11-45bf-b9b1-b768b54459c9/a99276f8-2570-4e18-93bd-f94e76c1606bomero.api.IConfig(omero.api._IConfigTie@122f17b) 2011-11-10 18:34:15,216 INFO [ ome.services.util.ServiceHandler] (l.Server-7) Meth: interface ome.api.IConfig.getConfigValue 2011-11-10 18:34:15,217 INFO [ ome.services.util.ServiceHandler] (l.Server-7) Args: [omero.router.insecure] 2011-11-10 18:34:15,231 INFO [ ome.security.basic.EventHandler] (l.Server-7) Auth: user=0,group=0,event=365(User),sess=89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:34:15,235 INFO [ org.perf4j.TimingLogger] (l.Server-7) start[1320975255217] time[18] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue] 2011-11-10 18:34:15,235 INFO [ ome.services.util.ServiceHandler] (l.Server-7) Rslt: OMERO.Glacier2/router:tcp -p 4063 -h @omero.host@ 2011-11-10 18:34:15,260 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-4) Found session locally: 89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:34:15,262 INFO [ ome.services.blitz.fire.SessionManagerI] (l.Server-4) Rejoining session ServiceFactoryI(session-061e1e95-f351-440b-9139-05e943a5d9d8/89e90972-ff11-45bf-b9b1-b768b54459c9) (agent=OMERO.insight;secure=false) 2011-11-10 18:34:15,363 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-8) Added servant to adapter: 89e90972-ff11-45bf-b9b1-b768b54459c9/a99276f8-2570-4e18-93bd-f94e76c1606bomero.api.IAdmin(omero.api._IAdminTie@ee8874) 2011-11-10 18:34:15,401 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Meth: interface ome.api.IAdmin.lookupExperimenter 2011-11-10 18:34:15,401 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Args: [root] 2011-11-10 18:34:15,403 INFO [ ome.security.basic.EventHandler] (l.Server-2) Auth: user=0,group=0,event=null(User),sess=89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:34:15,415 INFO [ org.perf4j.TimingLogger] (l.Server-2) start[1320975255401] time[14] tag[omero.call.success.ome.logic.AdminImpl.lookupExperimenter] 2011-11-10 18:34:15,415 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Rslt: ome.model.meta.Experimenter:Id_0 2011-11-10 18:34:15,526 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-5) Added servant to adapter: 89e90972-ff11-45bf-b9b1-b768b54459c9/061e1e95-f351-440b-9139-05e943a5d9d8omero.api.IConfig(omero.api._IConfigTie@1472b3c) 2011-11-10 18:34:15,530 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Meth: interface ome.api.IConfig.getVersion 2011-11-10 18:34:15,530 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Args: () 2011-11-10 18:34:15,551 INFO [ ome.security.basic.EventHandler] (l.Server-5) Auth: user=0,group=0,event=366(User),sess=89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:34:15,558 INFO [ org.perf4j.TimingLogger] (l.Server-5) start[1320975255530] time[28] tag[omero.call.success.ome.logic.ConfigImpl.getVersion] 2011-11-10 18:34:15,558 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Rslt: 4.3.3 2011-11-10 18:34:15,601 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Meth: interface ome.api.IAdmin.getEventContext 2011-11-10 18:34:15,602 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Args: () 2011-11-10 18:34:15,604 INFO [ ome.security.basic.EventHandler] (l.Server-6) Auth: user=0,group=0,event=null(User),sess=89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:34:15,620 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Executor.doWork -- ome.services.sessions.SessionManagerImpl.reload(89e90972-ff11-45bf-b9b1-b768b54459c9) 2011-11-10 18:34:15,621 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Args: [null, InternalSF@11104210] 2011-11-10 18:34:15,625 INFO [ ome.security.basic.EventHandler] (2-thread-1) Auth: user=0,group=0,event=null(Sessions),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:34:15,633 INFO [ org.perf4j.TimingLogger] (2-thread-1) start[1320975255621] time[12] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$6.doWork] 2011-11-10 18:34:15,633 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:34:15,634 INFO [ org.perf4j.TimingLogger] (l.Server-6) start[1320975255602] time[32] tag[omero.call.success.ome.logic.AdminImpl.getEventContext] 2011-11-10 18:34:15,634 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Rslt: ome.system.SimpleEventContext@1ef490c 2011-11-10 18:34:15,642 INFO [ ome.services.util.ServiceHandler] (l.Server-9) Meth: interface ome.api.IAdmin.lookupLdapAuthExperimenter 2011-11-10 18:34:15,642 INFO [ ome.services.util.ServiceHandler] (l.Server-9) Args: [0] 2011-11-10 18:34:15,643 INFO [ ome.security.basic.EventHandler] (l.Server-9) Auth: user=0,group=0,event=null(User),sess=89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:34:15,644 INFO [ org.perf4j.TimingLogger] (l.Server-9) start[1320975255642] time[2] tag[omero.call.success.ome.logic.AdminImpl.lookupLdapAuthExperimenter] 2011-11-10 18:34:15,644 INFO [ ome.services.util.ServiceHandler] (l.Server-9) Rslt: null 2011-11-10 18:34:15,647 INFO [ ome.services.util.ServiceHandler] (l.Server-7) Meth: interface ome.api.IAdmin.getEventContext 2011-11-10 18:34:15,647 INFO [ ome.services.util.ServiceHandler] (l.Server-7) Args: () 2011-11-10 18:34:15,648 INFO [ ome.security.basic.EventHandler] (l.Server-7) Auth: user=0,group=0,event=null(User),sess=89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:34:15,648 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Executor.doWork -- ome.services.sessions.SessionManagerImpl.reload(89e90972-ff11-45bf-b9b1-b768b54459c9) 2011-11-10 18:34:15,648 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Args: [null, InternalSF@11104210] 2011-11-10 18:34:15,649 INFO [ ome.security.basic.EventHandler] (2-thread-1) Auth: user=0,group=0,event=null(Sessions),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:34:15,662 INFO [ org.perf4j.TimingLogger] (2-thread-1) start[1320975255648] time[14] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$6.doWork] 2011-11-10 18:34:15,662 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:34:15,663 INFO [ org.perf4j.TimingLogger] (l.Server-7) start[1320975255647] time[16] tag[omero.call.success.ome.logic.AdminImpl.getEventContext] 2011-11-10 18:34:15,663 INFO [ ome.services.util.ServiceHandler] (l.Server-7) Rslt: ome.system.SimpleEventContext@77d0d6 2011-11-10 18:34:15,667 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-1) Added servant to adapter: 89e90972-ff11-45bf-b9b1-b768b54459c9/061e1e95-f351-440b-9139-05e943a5d9d8omero.api.IQuery(omero.api._IQueryTie@bb855b) 2011-11-10 18:34:15,700 INFO [ ome.services.util.ServiceHandler] (l.Server-4) Meth: interface ome.api.IQuery.findAllByQuery 2011-11-10 18:34:15,700 INFO [ ome.services.util.ServiceHandler] (l.Server-4) Args: [select distinct g from ExperimenterGroup as g join fetch g.groupExperimenterMap as map join fetch map.parent e left outer join fetch map.child u left outer join fetch u.groupExperimenterMap m2 left outer join fetch m2.parent p where g.id in (select m.parent from GroupExperimenterMap m where m.child.id = :id ), PARAMS:id=0 ] 2011-11-10 18:34:15,701 INFO [ ome.security.basic.EventHandler] (l.Server-4) Auth: user=0,group=0,event=null(User),sess=89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:34:16,099 INFO [ org.perf4j.TimingLogger] (l.Server-4) start[1320975255700] time[399] tag[omero.call.success.ome.logic.QueryImpl.findAllByQuery] 2011-11-10 18:34:16,099 INFO [ ome.services.util.ServiceHandler] (l.Server-4) Rslt: (ome.model.meta.ExperimenterGroup:Id_1, ome.model.meta.ExperimenterGroup:Id_0) 2011-11-10 18:34:28,123 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Meth: interface ome.api.IAdmin.getEventContext 2011-11-10 18:34:28,123 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Args: () 2011-11-10 18:34:28,124 INFO [ ome.security.basic.EventHandler] (l.Server-2) Auth: user=0,group=0,event=null(User),sess=89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:34:28,125 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Executor.doWork -- ome.services.sessions.SessionManagerImpl.reload(89e90972-ff11-45bf-b9b1-b768b54459c9) 2011-11-10 18:34:28,125 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Args: [null, InternalSF@11104210] 2011-11-10 18:34:28,126 INFO [ ome.security.basic.EventHandler] (2-thread-1) Auth: user=0,group=0,event=null(Sessions),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:34:28,134 INFO [ org.perf4j.TimingLogger] (2-thread-1) start[1320975268125] time[9] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$6.doWork] 2011-11-10 18:34:28,134 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:34:28,135 INFO [ org.perf4j.TimingLogger] (l.Server-2) start[1320975268123] time[12] tag[omero.call.success.ome.logic.AdminImpl.getEventContext] 2011-11-10 18:34:28,136 INFO [ ome.services.util.ServiceHandler] (l.Server-2) Rslt: ome.system.SimpleEventContext@1c3fd59 2011-11-10 18:34:28,154 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-0) Added servant to adapter: 89e90972-ff11-45bf-b9b1-b768b54459c9/061e1e95-f351-440b-9139-05e943a5d9d8omero.api.IContainer(omero.api._IContainerTie@1bf8785) 2011-11-10 18:34:28,226 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Meth: interface ome.api.IContainer.loadContainerHierarchy 2011-11-10 18:34:28,226 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Args: [class ome.model.containers.Project, (), PARAMS:F(u0):O[O]] 2011-11-10 18:34:28,227 INFO [ ome.security.basic.EventHandler] (l.Server-5) Auth: user=0,group=0,event=null(User),sess=89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:34:28,503 INFO [ org.perf4j.TimingLogger] (l.Server-5) start[1320975268226] time[277] tag[omero.call.success.ome.logic.PojosImpl.loadContainerHierarchy] 2011-11-10 18:34:28,503 INFO [ ome.services.util.ServiceHandler] (l.Server-5) Rslt: () 2011-11-10 18:34:53,431 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Meth: interface ome.api.IAdmin.getEventContext 2011-11-10 18:34:53,432 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Args: () 2011-11-10 18:34:53,434 INFO [ ome.security.basic.EventHandler] (l.Server-6) Auth: user=0,group=0,event=null(User),sess=89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:34:53,435 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Executor.doWork -- ome.services.sessions.SessionManagerImpl.reload(89e90972-ff11-45bf-b9b1-b768b54459c9) 2011-11-10 18:34:53,435 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Args: [null, InternalSF@11104210] 2011-11-10 18:34:53,437 INFO [ ome.security.basic.EventHandler] (2-thread-1) Auth: user=0,group=0,event=null(Sessions),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:34:53,445 INFO [ org.perf4j.TimingLogger] (2-thread-1) start[1320975293435] time[10] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$6.doWork] 2011-11-10 18:34:53,445 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, [0, 1], ... 4 more) 2011-11-10 18:34:53,446 INFO [ org.perf4j.TimingLogger] (l.Server-6) start[1320975293432] time[14] tag[omero.call.success.ome.logic.AdminImpl.getEventContext] 2011-11-10 18:34:53,446 INFO [ ome.services.util.ServiceHandler] (l.Server-6) Rslt: ome.system.SimpleEventContext@496381 2011-11-10 18:34:53,452 INFO [ ome.services.util.ServiceHandler] (l.Server-9) Meth: interface ome.api.IContainer.loadContainerHierarchy 2011-11-10 18:34:53,452 INFO [ ome.services.util.ServiceHandler] (l.Server-9) Args: [class ome.model.screen.Screen, (), PARAMS:F(u0):O[O]] 2011-11-10 18:34:53,453 INFO [ ome.security.basic.EventHandler] (l.Server-9) Auth: user=0,group=0,event=null(User),sess=89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:34:53,511 INFO [ org.perf4j.TimingLogger] (l.Server-9) start[1320975293452] time[59] tag[omero.call.success.ome.logic.PojosImpl.loadContainerHierarchy] 2011-11-10 18:34:53,511 INFO [ ome.services.util.ServiceHandler] (l.Server-9) Rslt: () 2011-11-10 18:35:30,164 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Executor.doWork -- ome.services.sessions.SessionManagerImpl.executeCheckPasswordRO(steveo) 2011-11-10 18:35:30,164 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Args: [null, InternalSF@11104210] 2011-11-10 18:35:30,165 INFO [ ome.security.basic.EventHandler] (l.Server-0) Auth: user=0,group=0,event=null(Sessions),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:35:30,167 INFO [ org.perf4j.TimingLogger] (l.Server-0) start[1320975330164] time[3] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$8.doWork] 2011-11-10 18:35:30,167 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Rslt: null 2011-11-10 18:35:30,170 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Executor.doWork -- ome.services.sessions.SessionManagerImpl.executeCheckPasswordRW(steveo) 2011-11-10 18:35:30,170 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Args: [null, InternalSF@11104210] 2011-11-10 18:35:30,187 INFO [ ome.security.basic.EventHandler] (l.Server-0) Auth: user=0,group=0,event=367(Sessions),sess=a54103c5-e98f-4765-b536-cbd5fa8b946f 2011-11-10 18:35:30,360 INFO [ ome.security.auth.LdapPasswordProvider] (l.Server-0) Default choice on create user: steveo (ome.conditions.ApiUsageException: Cannot find unique DistinguishedName: found=0) 2011-11-10 18:35:30,362 INFO [ org.perf4j.TimingLogger] (l.Server-0) start[1320975330170] time[192] tag[omero.call.exception] 2011-11-10 18:35:30,364 WARN [ ome.services.util.ServiceHandler] (l.Server-0) Unknown exception thrown. java.lang.NullPointerException at ome.security.auth.LdapPasswordProvider.checkPassword(LdapPasswordProvider.java:106) at ome.security.auth.PasswordProviders.checkPassword(PasswordProviders.java:42) at ome.logic.AdminImpl.checkPassword(AdminImpl.java:1194) at ome.services.sessions.SessionManagerImpl$9.doWork(SessionManagerImpl.java:978) at sun.reflect.GeneratedMethodAccessor270.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:616) 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.services.util.Executor$Impl$Interceptor.invoke(Executor.java:440) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at ome.security.basic.EventHandler.invoke(EventHandler.java:150) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111) 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 $Proxy64.doWork(Unknown Source) at ome.services.util.Executor$Impl.execute(Executor.java:371) at ome.services.sessions.SessionManagerImpl.executeCheckPasswordRW(SessionManagerImpl.java:973) at ome.services.sessions.SessionManagerImpl.executeCheckPassword(SessionManagerImpl.java:945) at ome.services.sessions.SessionManagerImpl.executePasswordCheck(SessionManagerImpl.java:920) at ome.services.blitz.fire.PermissionsVerifierI.checkPermissions(PermissionsVerifierI.java:135) at Glacier2._PermissionsVerifierDisp.___checkPermissions(_PermissionsVerifierDisp.java:90) at Glacier2._PermissionsVerifierDisp.__dispatch(_PermissionsVerifierDisp.java:118) 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) 2011-11-10 18:35:30,365 INFO [ ome.services.util.ServiceHandler] (l.Server-0) Excp: java.lang.NullPointerException 2011-11-10 18:35:30,365 ERROR [services.blitz.fire.PermissionsVerifierI] (l.Server-0) Exception thrown while checking password for:steveo ome.conditions.InternalException: Wrapped Exception: (java.lang.NullPointerException): null at ome.security.auth.LdapPasswordProvider.checkPassword(LdapPasswordProvider.java:106) at ome.security.auth.PasswordProviders.checkPassword(PasswordProviders.java:42) at ome.logic.AdminImpl.checkPassword(AdminImpl.java:1194) at ome.services.sessions.SessionManagerImpl$9.doWork(SessionManagerImpl.java:978) at sun.reflect.GeneratedMethodAccessor270.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:616) 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.services.util.Executor$Impl$Interceptor.invoke(Executor.java:440) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at ome.security.basic.EventHandler.invoke(EventHandler.java:150) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111) 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 $Proxy64.doWork(Unknown Source) at ome.services.util.Executor$Impl.execute(Executor.java:371) at ome.services.sessions.SessionManagerImpl.executeCheckPasswordRW(SessionManagerImpl.java:973) at ome.services.sessions.SessionManagerImpl.executeCheckPassword(SessionManagerImpl.java:945) at ome.services.sessions.SessionManagerImpl.executePasswordCheck(SessionManagerImpl.java:920) at ome.services.blitz.fire.PermissionsVerifierI.checkPermissions(PermissionsVerifierI.java:135) at Glacier2._PermissionsVerifierDisp.___checkPermissions(_PermissionsVerifierDisp.java:90) at Glacier2._PermissionsVerifierDisp.__dispatch(_PermissionsVerifierDisp.java:118) 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) 2011-11-10 18:36:00,033 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-4) Performing requestHeartbeats 2011-11-10 18:39:00,019 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-3) Performing requestHeartbeats 2011-11-10 18:42:00,016 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-1) Performing requestHeartbeats 2011-11-10 18:45:00,019 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-4) Performing requestHeartbeats 2011-11-10 18:46:27,177 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Session already removed. Cleaning up blitz state. 2011-11-10 18:46:27,177 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-3) Session already removed. Cleaning up blitz state. 2011-11-10 18:46:27,177 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) doDestroy(ServiceFactoryI(session-a99276f8-2570-4e18-93bd-f94e76c1606b/89e90972-ff11-45bf-b9b1-b768b54459c9)) 2011-11-10 18:46:27,178 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-3) doDestroy(ServiceFactoryI(session-061e1e95-f351-440b-9139-05e943a5d9d8/89e90972-ff11-45bf-b9b1-b768b54459c9)) 2011-11-10 18:46:27,178 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Unregistered servant:89e90972-ff11-45bf-b9b1-b768b54459c9/a99276f8-2570-4e18-93bd-f94e76c1606bomero.api.IConfig(omero.api._IConfigTie@122f17b) 2011-11-10 18:46:27,178 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Removed servant from adapter: a99276f8-2570-4e18-93bd-f94e76c1606bomero.api.IConfig 2011-11-10 18:46:27,179 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Unregistered servant:89e90972-ff11-45bf-b9b1-b768b54459c9/061e1e95-f351-440b-9139-05e943a5d9d8omero.api.IQuery(omero.api._IQueryTie@bb855b) 2011-11-10 18:46:27,179 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Removed servant from adapter: 061e1e95-f351-440b-9139-05e943a5d9d8omero.api.IQuery 2011-11-10 18:46:27,179 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Unregistered servant:89e90972-ff11-45bf-b9b1-b768b54459c9/061e1e95-f351-440b-9139-05e943a5d9d8omero.api.IConfig(omero.api._IConfigTie@1472b3c) 2011-11-10 18:46:27,179 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Removed servant from adapter: 061e1e95-f351-440b-9139-05e943a5d9d8omero.api.IConfig 2011-11-10 18:46:27,179 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Unregistered servant:89e90972-ff11-45bf-b9b1-b768b54459c9/061e1e95-f351-440b-9139-05e943a5d9d8omero.api.IContainer(omero.api._IContainerTie@1bf8785) 2011-11-10 18:46:27,179 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Removed servant from adapter: 061e1e95-f351-440b-9139-05e943a5d9d8omero.api.IContainer 2011-11-10 18:46:27,179 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Unregistered servant:89e90972-ff11-45bf-b9b1-b768b54459c9/a99276f8-2570-4e18-93bd-f94e76c1606bomero.api.IAdmin(omero.api._IAdminTie@ee8874) 2011-11-10 18:46:27,179 INFO [ ome.services.blitz.impl.ServiceFactoryI] (l.Server-7) Removed servant from adapter: a99276f8-2570-4e18-93bd-f94e76c1606bomero.api.IAdmin 2011-11-10 18:46:27,179 INFO [ome.services.sessions.SessionManagerImpl] (l.Server-7) closeSession called but doesn't exist: 89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:46:27,179 INFO [ome.services.sessions.SessionManagerImpl] (l.Server-3) closeSession called but doesn't exist: 89e90972-ff11-45bf-b9b1-b768b54459c9 2011-11-10 18:48:00,018 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-2) Performing requestHeartbeats 2011-11-10 18:51:00,018 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-1) Performing requestHeartbeats 2011-11-10 18:54:00,028 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-5) Performing requestHeartbeats 2011-11-10 18:57:00,024 INFO [ ome.services.blitz.fire.SessionManagerI] (3-thread-2) Performing requestHeartbeats