Problem using cleanse

[rdecoster]

it all began with a bugreport following a failed import where the user gave a wrong dataset_id to import at.
https://www.openmicroscopy.org/qa2/qa/f ... 4515f328c1

When trying to import that file again with the right dataset_id it fails because there is a checksum match. Via the web interface there is no trace of it however.

To solve that Colin Blackburn suggested I run the cleanse command. This was the first time I ran it and it failed with the error below.
Restarting does not help indeed and yes I restarted today. At some point I also tried removing it manually from the managedrepository (file location) but that doesn't help as well it seems.

Is there any way to get more debug info on where the cleanse actually fails?

Best,
Raf

[cblackburn]

Hi Raf,

Assuming you can, at least temporarily, live with the duplicated data in the file store, it may be better to look at removing those files later and try to get the import to work for now. Can you confirm what import command was originally used for the failed import, did it use the

Code: Select all

--exclude=filename

option? If so then trying the import again without this exclude option (and without the inaccessible Dataset being specified) should succeed.

If the image can be imported without the Dataset specified it can later be moved between groups and in to the correct Dataset using Insight or the webclient.

Cheers,

Colin

[rdecoster]

Apologies my late reply.

Yes indeed we used the exclude option. I just upgraded to the latest omero version and tried to upload without exclude option and with datasetid option. That works, thank you.
Our setup is as follows: user have access to a file share where they can place and organize their files. If they want certain files imported they should place an "import.txt" file in the folder they want to import. This should contain the omero username to import to and the dataset id (they created previously via web). This import.txt get's picked up by a cron job that imports into omero.
the actuall line doing that is:

Code: Select all

OMERO.server/bin/omero import --create --server localhost:4064 --depth 10 --user ${id} --skip checksum --sudo root --password xxx --group $group --report --upload --logs --email raf.decoster@kuleuven.be -- --transfer=ln --exclude=filename "${file:0:$config_file_string_length}"

another thing to know: we have several groups in omero (individual labs) that are not allowed to access the other groups.

The problem with cleanse and the failed import (saying it's duplicate) came up when a user entered a datasetid that belongs to another group/lab where she did not have access to

Anyway after the working import I ran cleanse again. Unfortunately with the same message ... if you have some ideas left to tackle this problem I'm happy to try them.

Thanks for your time!
best,
Raf

[cblackburn]

Hi Raf,

Thanks for confirming that the import without the `--exclude=filename` succeeded. It looks like there may be a couple of unrelated issues here.

One is a bug in cleanse in dealing duplicate repositories. I've opened a ticket to look at this and can add you to the cc list if you wish to be kept informed. See: https://trac.openmicroscopy.org/ome/ticket/13251

The second is why the import was excluded. The original failed import where the user provided the wrong Dataset id should not have uploaded any files or created any related entries in the database. So it is possible the exclusion, once the id was corrected, was for other reasons.

Firstly, is it possible that the user imported the image independently of your automated import system, ie manually? If they did this then the second automated attempt with the correct Dataset id would fail. Is it possoble to check if the user does have any duplicated images that might explain this?

Secondly, using `--skip checksum` means that the checksum is simply based on the file size. This means that files with the same name and same size would be excluded from import. Does your acquisition system create files with names that might clash somehow? Does it produce files of identical sizes?

Sorry for more questions than answers here, but any further help you can give would be greatly appreciated.

Cheers,

Colin

[rdecoster]

Firstly, is it possible that the user imported the image independently of your automated import system, ie manually?

She did not she tells and I did not find evidence she did

Is it possoble to check if the user does have any duplicated images that might explain this?

Bingo! I should have checked that ...

Code: Select all

omero@gbw-s-omero01:~$ locate 20150512-G1-Notchmut-Lamp1.lif
/media/GBW-0004_CMEVIB_OMERO/0003_WIAN/Ragna/Notch mutant/G1-Notch1_mut/20150512-G1-Notchmut-Lamp1.lif
/media/GBW-0004_CMEVIB_OMERO/BioFormatsCache/media/GBW-0004_CMEVIB_OMERO/ManagedRepository/GBW.GS.ISPAMM.WIAN/u0050670/2016-05/12/18-12-12.934/.20150512-G1-Notchmut-Lamp1.lif.bfmemo
/media/GBW-0004_CMEVIB_OMERO/BioFormatsCache/media/GBW-0004_CMEVIB_OMERO/ManagedRepository/GBW.GS.ISPAMM.WIAN/u0050670/2016-06/07/21-51-20.478/.20150512-G1-Notchmut-Lamp1.lif.bfmemo
/media/GBW-0004_CMEVIB_OMERO/ManagedRepository/GBW.GS.ISPAMM.WIAN/u0050670/2016-05/12/18-12-12.934/20150512-G1-Notchmut-Lamp1.lif
/media/GBW-0004_CMEVIB_OMERO/ManagedRepository/GBW.GS.ISPAMM.WIAN/u0050670/2016-06/07/21-51-20.478/20150512-G1-Notchmut-Lamp1.lif


Here is the logfile of the first import on 12-05-2016

Code: Select all

2016-05-12 18:12:15,492 INFO  [    ome.formats.OMEROMetadataStoreClient] (2-thread-4) Call context: {omero.logfilename:GBW.GS.ISPAMM.WIAN/u0050670/2016-05/12/18-12-12.934.log}
2016-05-12 18:12:15,682 INFO  [         ome.security.basic.EventHandler] (Server-111)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:16,668 INFO  [                loci.formats.ImageReader] (2-thread-4) LIFReader initializing /media/GBW-0004_CMEVIB_OMERO/ManagedRepository/GBW.GS.ISPAMM.WIAN/u0050670/2016-05/12/18-12-12.934/20150512-G1-Notchmut-Lamp1.lif
2016-05-12 18:12:16,678 INFO  [              loci.formats.FormatHandler] (2-thread-4) Reading header
2016-05-12 18:12:16,684 INFO  [              loci.formats.FormatHandler] (2-thread-4) Finding image offsets
2016-05-12 18:12:16,785 INFO  [         ome.security.basic.EventHandler] (Server-106)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:16,789 INFO  [         ome.security.basic.EventHandler] (Server-112)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:16,796 INFO  [         ome.security.basic.EventHandler] (Server-113)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:16,801 INFO  [         ome.security.basic.EventHandler] (Server-111)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:16,806 INFO  [         ome.security.basic.EventHandler] (Server-108)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:16,811 INFO  [         ome.security.basic.EventHandler] (Server-106)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:16,823 INFO  [         ome.security.basic.EventHandler] (Server-112)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:16,839 INFO  [         ome.security.basic.EventHandler] (Server-113)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:16,843 INFO  [         ome.security.basic.EventHandler] (Server-111)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:16,847 INFO  [         ome.security.basic.EventHandler] (Server-108)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:16,979 DEBUG [                   loci.formats.Memoizer] (2-thread-4) saved to temp file: /media/GBW-0004_CMEVIB_OMERO/BioFormatsCache/media/GBW-0004_CMEVIB_OMERO/ManagedRepository/GBW.GS.ISPAMM.WIAN/u0050670/2016-05/12/18-12-12.934/.20150512-G1-Notchmut-Lamp1.lif.bfmemo5458821887203601340
2016-05-12 18:12:16,979 DEBUG [                   loci.formats.Memoizer] (2-thread-4) start[1463069536862] time[117] tag[loci.formats.Memoizer.saveMemo]
2016-05-12 18:12:16,986 DEBUG [                   loci.formats.Memoizer] (2-thread-4) saved memo file: /media/GBW-0004_CMEVIB_OMERO/BioFormatsCache/media/GBW-0004_CMEVIB_OMERO/ManagedRepository/GBW.GS.ISPAMM.WIAN/u0050670/2016-05/12/18-12-12.934/.20150512-G1-Notchmut-Lamp1.lif.bfmemo (100198 bytes)
2016-05-12 18:12:16,986 DEBUG [                   loci.formats.Memoizer] (2-thread-4) start[1463069535727] time[1258] tag[loci.formats.Memoizer.setId]
2016-05-12 18:12:16,986 DEBUG [    o.s.blitz.repo.ManagedImportRequestI] (2-thread-4) Image Count: 3
2016-05-12 18:12:16,986 INFO  [    o.s.blitz.repo.ManagedImportRequestI] (2-thread-4) File format: Leica Image File Format
2016-05-12 18:12:16,986 INFO  [    o.s.blitz.repo.ManagedImportRequestI] (2-thread-4) Base reader: loci.formats.in.LIFReader
2016-05-12 18:12:16,986 DEBUG [    o.s.blitz.repo.ManagedImportRequestI] (2-thread-4) Step 0
2016-05-12 18:12:16,988 WARN  [    ome.formats.model.ReferenceProcessor] (2-thread-4) Unknown target class for LSID: Image:1
2016-05-12 18:12:16,988 WARN  [    ome.formats.model.ReferenceProcessor] (2-thread-4) Unknown target class for LSID: Image:0
2016-05-12 18:12:16,988 INFO  [    ome.formats.OMEROMetadataStoreClient] (2-thread-4) Handling # of containers: 80
2016-05-12 18:12:16,995 INFO  [         ome.security.basic.EventHandler] (Server-106)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:17,000 INFO  [    ome.formats.OMEROMetadataStoreClient] (2-thread-4) Handling # of references: 20
2016-05-12 18:12:17,002 INFO  [         ome.security.basic.EventHandler] (Server-112)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:17,018 INFO  [         ome.security.basic.EventHandler] (Server-113)  Auth:   user=202,group=53,event=1444502(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:17,034 DEBUG [                    omero.util.IceMapper] (Server-113) Handling:
ome.conditions.SecurityViolation: Group is rwra--. Cannot link to object: ome.model.containers.Dataset:Id_501
   at ome.security.basic.OmeroInterceptor.throwIfNotGranted(OmeroInterceptor.java:1141) ~[server.jar:na]
   at ome.security.basic.OmeroInterceptor.evaluateLinkages(OmeroInterceptor.java:549) ~[server.jar:na]
   at ome.security.basic.OmeroInterceptor.onSave(OmeroInterceptor.java:157) ~[server.jar:na]
   at org.hibernate.event.def.AbstractSaveEventListener.substituteValuesIfNecessary(AbstractSaveEventListener.java:414) ~[hibernate-core.jar:na]
   at org.hibernate.event.def.AbstractSaveEventListener.performSaveOrReplicate(AbstractSaveEventListener.java:293) ~[hibernate-core.jar:na]
   at org.hibernate.event.def.AbstractSaveEventListener.performSave(AbstractSaveEventListener.java:204) ~[hibernate-core.jar:na]
   at org.hibernate.event.def.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:144) ~[hibernate-core.jar:na]
   at org.hibernate.event.def.DefaultMergeEventListener.saveTransientEntity(DefaultMergeEventListener.java:415) ~[hibernate-core.jar:na]
   at org.hibernate.event.def.DefaultMergeEventListener.mergeTransientEntity(DefaultMergeEventListener.java:341) ~[hibernate-core.jar:na]
   at org.hibernate.event.def.DefaultMergeEventListener.entityIsTransient(DefaultMergeEventListener.java:303) ~[hibernate-core.jar:na]
   at org.springframework.orm.hibernate3.support.IdTransferringMergeEventListener.entityIsTransient(IdTransferringMergeEventListener.java:59) ~[spring-orm.jar:3.0.1.RELEASE]
   at ome.security.basic.MergeEventListener.entityIsTransient(MergeEventListener.java:157) ~[server.jar:na]
   at org.hibernate.event.def.DefaultMergeEventListener.onMerge(DefaultMergeEventListener.java:258) ~[hibernate-core.jar:na]
   at ome.security.basic.MergeEventListener.onMerge(MergeEventListener.java:90) ~[server.jar:na]
   at org.hibernate.impl.SessionImpl.fireMerge(SessionImpl.java:871) ~[hibernate-core.jar:na]
   at org.hibernate.impl.SessionImpl.merge(SessionImpl.java:853) ~[hibernate-core.jar:na]
   at org.hibernate.engine.CascadingAction$6.cascade(CascadingAction.java:279) ~[hibernate-core.jar:na]
   at org.hibernate.engine.Cascade.cascadeToOne(Cascade.java:392) ~[hibernate-core.jar:na]
   at org.hibernate.engine.Cascade.cascadeAssociation(Cascade.java:335) ~[hibernate-core.jar:na]
   at org.hibernate.engine.Cascade.cascadeProperty(Cascade.java:204) ~[hibernate-core.jar:na]
   at org.hibernate.engine.Cascade.cascadeCollectionElements(Cascade.java:425) ~[hibernate-core.jar:na]
   at org.hibernate.engine.Cascade.cascadeCollection(Cascade.java:362) ~[hibernate-core.jar:na]
   at org.hibernate.engine.Cascade.cascadeAssociation(Cascade.java:338) ~[hibernate-core.jar:na]
   at org.hibernate.engine.Cascade.cascadeProperty(Cascade.java:204) ~[hibernate-core.jar:na]
   at org.hibernate.engine.Cascade.cascade(Cascade.java:161) ~[hibernate-core.jar:na]
   at org.hibernate.event.def.AbstractSaveEventListener.cascadeAfterSave(AbstractSaveEventListener.java:476) ~[hibernate-core.jar:na]
   at org.hibernate.event.def.DefaultMergeEventListener.mergeTransientEntity(DefaultMergeEventListener.java:388) ~[hibernate-core.jar:na]
   at org.hibernate.event.def.DefaultMergeEventListener.entityIsTransient(DefaultMergeEventListener.java:303) ~[hibernate-core.jar:na]
   at org.springframework.orm.hibernate3.support.IdTransferringMergeEventListener.entityIsTransient(IdTransferringMergeEventListener.java:59) ~[spring-orm.jar:3.0.1.RELEASE]
   at ome.security.basic.MergeEventListener.entityIsTransient(MergeEventListener.java:157) ~[server.jar:na]
   at org.hibernate.event.def.DefaultMergeEventListener.onMerge(DefaultMergeEventListener.java:258) ~[hibernate-core.jar:na]
   at ome.security.basic.MergeEventListener.onMerge(MergeEventListener.java:90) ~[server.jar:na]
   at org.hibernate.event.def.DefaultMergeEventListener.onMerge(DefaultMergeEventListener.java:84) ~[hibernate-core.jar:na]
   at ome.security.basic.MergeEventListener.onMerge(MergeEventListener.java:76) ~[server.jar:na]
   at org.hibernate.impl.SessionImpl.fireMerge(SessionImpl.java:861) ~[hibernate-core.jar:na]
   at org.hibernate.impl.SessionImpl.merge(SessionImpl.java:845) ~[hibernate-core.jar:na]
   at org.hibernate.impl.SessionImpl.merge(SessionImpl.java:849) ~[hibernate-core.jar:na]
   at ome.logic.UpdateImpl.internalMerge(UpdateImpl.java:274) ~[server.jar:na]
   at ome.logic.UpdateImpl$4.run(UpdateImpl.java:148) ~[server.jar:na]
   at ome.logic.UpdateImpl$4.run(UpdateImpl.java:143) ~[server.jar:na]
   at ome.logic.UpdateImpl.doAction(UpdateImpl.java:310) ~[server.jar:na]
   at ome.logic.UpdateImpl.doAction(UpdateImpl.java:302) ~[server.jar:na]
   at ome.logic.UpdateImpl.saveAndReturnArray(UpdateImpl.java:143) ~[server.jar:na]
   at ome.formats.OMEROMetadataStore.saveToDB(OMEROMetadataStore.java:2185) ~[server.jar:na]
   at ome.services.blitz.impl.MetadataStoreI$3.doWork(MetadataStoreI.java:214) ~[blitz.jar:na]
   at sun.reflect.GeneratedMethodAccessor299.invoke(Unknown Source) ~[na:na]
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_79]
   at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_79]
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307) [spring-aop.jar:3.0.1.RELEASE]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) [spring-aop.jar:3.0.1.RELEASE]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) [spring-aop.jar:3.0.1.RELEASE]
   at ome.services.util.Executor$Impl$Interceptor.invoke(Executor.java:562) ~[server.jar:na]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop.jar:3.0.1.RELEASE]
   at ome.security.basic.EventHandler.invoke(EventHandler.java:154) ~[server.jar:na]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop.jar:3.0.1.RELEASE]
   at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111) ~[spring-orm.jar:3.0.1.RELEASE]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop.jar:3.0.1.RELEASE]
   at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:108) ~[spring-tx.jar:3.0.1.RELEASE]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop.jar:3.0.1.RELEASE]
   at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:249) ~[server.jar:na]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop.jar:3.0.1.RELEASE]
   at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:121) ~[server.jar:na]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop.jar:3.0.1.RELEASE]
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) [spring-aop.jar:3.0.1.RELEASE]
   at com.sun.proxy.$Proxy70.doWork(Unknown Source) ~[na:na]
   at ome.services.util.Executor$Impl.execute(Executor.java:443) ~[server.jar:na]
   at ome.services.util.Executor$Impl.execute(Executor.java:387) ~[server.jar:na]
   at ome.services.throttling.Adapter.run(Adapter.java:50) ~[blitz.jar:na]
   at ome.services.throttling.InThreadThrottlingStrategy.runnableCall(InThreadThrottlingStrategy.java:89) [blitz.jar:na]
   at ome.services.blitz.impl.AbstractAmdServant.runnableCall(AbstractAmdServant.java:154) [blitz.jar:na]
   at ome.services.blitz.impl.MetadataStoreI.saveToDB_async(MetadataStoreI.java:208) [blitz.jar:na]
   at sun.reflect.GeneratedMethodAccessor1346.invoke(Unknown Source) ~[na:na]
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_79]
   at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_79]
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307) [spring-aop.jar:3.0.1.RELEASE]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) [spring-aop.jar:3.0.1.RELEASE]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) [spring-aop.jar:3.0.1.RELEASE]
   at omero.cmd.CallContext.invoke(CallContext.java:78) [blitz.jar:na]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop.jar:3.0.1.RELEASE]
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) [spring-aop.jar:3.0.1.RELEASE]
   at com.sun.proxy.$Proxy103.saveToDB_async(Unknown Source) [na:na]
   at omero.api._MetadataStoreTie.saveToDB_async(_MetadataStoreTie.java:84) [blitz.jar:na]
   at omero.api._MetadataStoreDisp.___saveToDB(_MetadataStoreDisp.java:246) [blitz.jar:na]
   at omero.api._MetadataStoreDisp.__dispatch(_MetadataStoreDisp.java:388) [blitz.jar:na]
   at IceInternal.Incoming.invoke(Incoming.java:222) [ice.jar:na]
   at Ice.ConnectionI.invokeAll(ConnectionI.java:2482) [ice.jar:na]
   at Ice.ConnectionI.dispatch(ConnectionI.java:1258) [ice.jar:na]
   at Ice.ConnectionI.message(ConnectionI.java:1213) [ice.jar:na]
   at IceInternal.ThreadPool.run(ThreadPool.java:321) [ice.jar:na]
   at IceInternal.ThreadPool.access$300(ThreadPool.java:12) [ice.jar:na]
   at IceInternal.ThreadPool$EventHandlerThread.run(ThreadPool.java:693) [ice.jar:na]
   at java.lang.Thread.run(Thread.java:745) [na:1.7.0_79]
2016-05-12 18:12:17,036 DEBUG [                    omero.util.IceMapper] (Server-113) Handling:
omero.SecurityViolation: null
   at omero.util.IceMapper.handleException(IceMapper.java:1363) ~[blitz.jar:na]
   at ome.services.throttling.Adapter.run(Adapter.java:52) ~[blitz.jar:na]
   at ome.services.throttling.InThreadThrottlingStrategy.runnableCall(InThreadThrottlingStrategy.java:89) [blitz.jar:na]
   at ome.services.blitz.impl.AbstractAmdServant.runnableCall(AbstractAmdServant.java:154) [blitz.jar:na]
   at ome.services.blitz.impl.MetadataStoreI.saveToDB_async(MetadataStoreI.java:208) [blitz.jar:na]
   at sun.reflect.GeneratedMethodAccessor1346.invoke(Unknown Source) ~[na:na]
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_79]
   at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_79]
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307) [spring-aop.jar:3.0.1.RELEASE]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) [spring-aop.jar:3.0.1.RELEASE]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) [spring-aop.jar:3.0.1.RELEASE]
   at omero.cmd.CallContext.invoke(CallContext.java:78) [blitz.jar:na]
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop.jar:3.0.1.RELEASE]
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) [spring-aop.jar:3.0.1.RELEASE]
   at com.sun.proxy.$Proxy103.saveToDB_async(Unknown Source) [na:na]
   at omero.api._MetadataStoreTie.saveToDB_async(_MetadataStoreTie.java:84) [blitz.jar:na]
   at omero.api._MetadataStoreDisp.___saveToDB(_MetadataStoreDisp.java:246) [blitz.jar:na]
   at omero.api._MetadataStoreDisp.__dispatch(_MetadataStoreDisp.java:388) [blitz.jar:na]
   at IceInternal.Incoming.invoke(Incoming.java:222) [ice.jar:na]
   at Ice.ConnectionI.invokeAll(ConnectionI.java:2482) [ice.jar:na]
   at Ice.ConnectionI.dispatch(ConnectionI.java:1258) [ice.jar:na]
   at Ice.ConnectionI.message(ConnectionI.java:1213) [ice.jar:na]
   at IceInternal.ThreadPool.run(ThreadPool.java:321) [ice.jar:na]
   at IceInternal.ThreadPool.access$300(ThreadPool.java:12) [ice.jar:na]
   at IceInternal.ThreadPool$EventHandlerThread.run(ThreadPool.java:693) [ice.jar:na]
   at java.lang.Thread.run(Thread.java:745) [na:1.7.0_79]
2016-05-12 18:12:17,053 INFO  [ o.s.b.r.ManagedImportRequestI.@2b3ac41d] (2-thread-4) Cancelled
2016-05-12 18:12:17,056 INFO  [         ome.security.basic.EventHandler] (Server-111)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:17,072 INFO  [         ome.security.basic.EventHandler] (Server-108)  Auth:   user=202,group=53,event=1444503(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:17,076 INFO  [       ome.security.basic.CurrentDetails] (Server-108) Adding log:UPDATE,class ome.model.core.OriginalFile,143182
2016-05-12 18:12:17,093 INFO  [         ome.security.basic.EventHandler] (Server-106)  Auth:   user=202,group=53,event=1444504(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:17,095 DEBUG [                omero.util.ServantHolder] (Server-106) Removed omero.api._RawFileStoreTie@adeeaffc from omero.util.ServantHolder@44301a97 as 2d626c40-f03e-42b4-979d-6ab653ba6074omero.api.RawFileStore
2016-05-12 18:12:17,095 INFO  [                      omero.cmd.SessionI] (Server-106) Unregistered servant:fc0b6743-a5e1-48e6-af5d-73f9c3916417/2d626c40-f03e-42b4-979d-6ab653ba6074omero.api.RawFileStore(omero.api._RawFileStoreTie@adeeaffc)
2016-05-12 18:12:17,105 INFO  [         ome.security.basic.EventHandler] (Server-112)  Auth:   user=202,group=53,event=1444505(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:17,107 DEBUG [                omero.util.ServantHolder] (Server-112) Removed omero.api._RawPixelsStoreTie@b2c79258 from omero.util.ServantHolder@44301a97 as dc3d44c8-e51c-440d-995f-4ddca444ff69omero.api.RawPixelsStore
2016-05-12 18:12:17,107 INFO  [                      omero.cmd.SessionI] (Server-112) Unregistered servant:fc0b6743-a5e1-48e6-af5d-73f9c3916417/dc3d44c8-e51c-440d-995f-4ddca444ff69omero.api.RawPixelsStore(omero.api._RawPixelsStoreTie@b2c79258)
2016-05-12 18:12:17,109 INFO  [         ome.security.basic.EventHandler] (Server-113)  Auth:   user=202,group=53,event=null(User),sess=fc0b6743-a5e1-48e6-af5d-73f9c3916417
2016-05-12 18:12:17,110 DEBUG [                omero.util.ServantHolder] (Server-113) Removed omero.api._ThumbnailStoreTie@5a22e0b9 from omero.util.ServantHolder@44301a97 as cfb22d72-fc3e-4f3f-a498-fad8810cc9d6omero.api.ThumbnailStore
2016-05-12 18:12:17,110 INFO  [                      omero.cmd.SessionI] (Server-113) Unregistered servant:fc0b6743-a5e1-48e6-af5d-73f9c3916417/cfb22d72-fc3e-4f3f-a498-fad8810cc9d6omero.api.ThumbnailStore(omero.api._ThumbnailStoreTie@5a22e0b9)
2016-05-12 18:12:17,110 DEBUG [                omero.util.ServantHolder] (Server-111) Removed omero.api._MetadataStoreTie@5bbed4c5 from omero.util.ServantHolder@44301a97 as 8205cc86-26a0-4aa8-b43f-be00479d3364omero.api.MetadataStore
2016-05-12 18:12:17,110 INFO  [                      omero.cmd.SessionI] (Server-111) Unregistered servant:fc0b6743-a5e1-48e6-af5d-73f9c3916417/8205cc86-26a0-4aa8-b43f-be00479d3364omero.api.MetadataStore(omero.api._MetadataStoreTie@5bbed4c5)
2016-05-12 18:12:17,110 INFO  [    o.s.blitz.repo.ManagedImportRequestI] (2-thread-4) Finalizing log file.


So it seems it failed importing because of datasetid 501 (which belongs to another lab) but it still did write the file in the managedrepository.

Secondly, using `--skip checksum` means that the checksum is simply based on the file size. This means that files with the same name and same size would be excluded from import. Does your acquisition system create files with names that might clash somehow? Does it produce files of identical sizes?

That should not be a problem since filenames contain a date in almost all our cases.
We did not have the skip checksum option at the beginning but noticed a dramatic speedup when disabling checksums (an import that took 1h48 took less than 14 min).
I also thought that this checksum was only to prevent data corruption, is that not the case? Since we create hardlinks instead of copying the file calculating checksums seems useless. (The checksum was calculated on the same file 2 times, before and after transfer)

Thx!
Raf

[cblackburn]

Hi Raf,

Many thanks for the reply. I think I now have a handle on what is happening.

The original import target was a Dataset in the correct group for the user but the Dataset belonged to a different user to the one importing their image. As this was a read-annotate group the Image could not be attached to that Dataset and so the import failed after the files had been uploaded and a Fileset created but before the Image was created. The existence of the files and Fileset was enough to prevent the second import attempt due to the `--exclude` option.

Coming on to how you can now remove this failed import, can you run the following CLI command,

Code: Select all

bin/omero hql "SELECT DISTINCT fileset FROM FilesetEntry WHERE fileset NOT IN (SELECT fileset FROM Image)" --all


as an admin user? This should list this "orphaned" Fileset along with details of its owner id and path in the repository, this should allow you to confirm that it is the correct Fileset.

This can then be deleted using,

Code: Select all

bin/omero delete Fileset:ID --report --dry-run


Note here that I am using the `--dry-run` option to see what would be deleted, this is good practice if there is any doubt in the effects of the delete. If the delete looks correct then running it again without the `--dry-run` option should delete the Fileset and the underlying binary files.

Note that if the `hql` query returns several ids then it may be worth holding off on the delete and looking at each Fileset in turn to check what files each is connected to.

Cheers,

Colin

[rdecoster]

Ok, I had 6 of these orphaned filesets.

Code: Select all

# | Class    | Id    | templatePrefix                                         | details
---+----------+-------+--------------------------------------------------------+--------------------
0 | FilesetI | 2261  | GBW.GS.ISPAMM.PAVE/u0083649/2016-02/03/22-48-12.933/   | owner=53;group=4
1 | FilesetI | 47100 | GBW.GS.ISPAMM.WIAN/u0050670/2016-05/12/18-12-12.934/   | owner=202;group=53
2 | FilesetI | 47118 | GBW.GS.ISPAMM.WIAN/u0050670/2016-05/13/08-41-21.408/   | owner=202;group=53
3 | FilesetI | 46277 | GBW.GS.ISPAMM.LIMONE/u0072210/2016-04/12/19-00-16.967/ | owner=154;group=3
4 | FilesetI | 2260  | GBW.GS.ISPAMM.PAVE/u0083649/2016-02/03/21-50-37.990/   | owner=53;group=4
5 | FilesetI | 46301 | GBW.GS.ISPAMM.LIMONE/u0072210/2016-04/12/21-58-26.864/ | owner=154;group=3
(6 rows)


I removed them all after inspecting. with 2 it was the datasetid prob, other 2 was a failed import due to unknown format. The other 2 had this:

Code: Select all

2016-04-12 21:58:27,523 INFO  [    ome.formats.OMEROMetadataStoreClient] (2-thread-4) Call context: {omero.logfilename:GBW.GS.ISPAMM.LIMONE/u0072210/2016-04/12/21-58-26.864.log}
2016-04-12 21:58:27,536 INFO  [         ome.security.basic.EventHandler] (Server-305)  Auth:   user=154,group=3,event=null(User),sess=888cc22a-45e9-4c64-87ee-143cb0a3f60b
2016-04-12 21:58:27,573 DEBUG [                   loci.formats.Memoizer] (2-thread-4) start[1460491107563] time[9] tag[loci.formats.Memoizer.setId]
2016-04-12 21:58:27,574 INFO  [ o.s.b.r.ManagedImportRequestI.@71db8424] (2-thread-4) Cancelled
2016-04-12 21:58:27,587 INFO  [         ome.security.basic.EventHandler] (Server-305)  Auth:   user=154,group=3,event=1404713(User),sess=888cc22a-45e9-4c64-87ee-143cb0a3f60b
2016-04-12 21:58:27,589 DEBUG [                omero.util.ServantHolder] (Server-305) Removed omero.api._RawFileStoreTie@33c53a1f from omero.util.ServantHolder@432ff3c6 as 364f2086-d619-4c47-8c79-7daf821f1ddaomero.api.RawFileStore
2016-04-12 21:58:27,589 INFO  [                      omero.cmd.SessionI] (Server-305) Unregistered servant:888cc22a-45e9-4c64-87ee-143cb0a3f60b/364f2086-d619-4c47-8c79-7daf821f1ddaomero.api.RawFileStore(omero.api._RawFileStoreTie@33c53a1f)
2016-04-12 21:58:27,600 INFO  [         ome.security.basic.EventHandler] (Server-306)  Auth:   user=154,group=3,event=1404714(User),sess=888cc22a-45e9-4c64-87ee-143cb0a3f60b
2016-04-12 21:58:27,601 DEBUG [                omero.util.ServantHolder] (Server-306) Removed omero.api._RawPixelsStoreTie@82a16523 from omero.util.ServantHolder@432ff3c6 as 07af069a-14cc-4c8c-8c86-85e16f7ac341omero.api.RawPixelsStore
2016-04-12 21:58:27,601 INFO  [                      omero.cmd.SessionI] (Server-306) Unregistered servant:888cc22a-45e9-4c64-87ee-143cb0a3f60b/07af069a-14cc-4c8c-8c86-85e16f7ac341omero.api.RawPixelsStore(omero.api._RawPixelsStoreTie@82a16523)
2016-04-12 21:58:27,603 INFO  [         ome.security.basic.EventHandler] (Server-304)  Auth:   user=154,group=3,event=null(User),sess=888cc22a-45e9-4c64-87ee-143cb0a3f60b
2016-04-12 21:58:27,604 DEBUG [                omero.util.ServantHolder] (Server-304) Removed omero.api._ThumbnailStoreTie@439ad50e from omero.util.ServantHolder@432ff3c6 as 93485b4d-e530-486b-a21a-7ef4d111089bomero.api.ThumbnailStore
2016-04-12 21:58:27,604 INFO  [                      omero.cmd.SessionI] (Server-304) Unregistered servant:888cc22a-45e9-4c64-87ee-143cb0a3f60b/93485b4d-e530-486b-a21a-7ef4d111089bomero.api.ThumbnailStore(omero.api._ThumbnailStoreTie@439ad50e)
2016-04-12 21:58:27,604 DEBUG [                omero.util.ServantHolder] (Server-307) Removed omero.api._MetadataStoreTie@51cd3930 from omero.util.ServantHolder@432ff3c6 as 9feb0823-c514-42d5-b788-71cd66743fe5omero.api.MetadataStore
2016-04-12 21:58:27,604 INFO  [                      omero.cmd.SessionI] (Server-307) Unregistered servant:888cc22a-45e9-4c64-87ee-143cb0a3f60b/9feb0823-c514-42d5-b788-71cd66743fe5omero.api.MetadataStore(omero.api._MetadataStoreTie@51cd3930)
2016-04-12 21:58:27,605 INFO  [    o.s.blitz.repo.ManagedImportRequestI] (2-thread-4) Finalizing log file.


It's cancelled, but for what reason ...

Can you add me to cc list of https://trac.openmicroscopy.org/ome/ticket/13251 ?

Thx for all the help Colin!

Cheers,
Raf

[cblackburn]

Hi Raf,

Ok, I had 6 of these orphaned filesets.

It's cancelled, but for what reason ...

Ah, sorry, the best way of working this out would have been to look at the import log. This is the `.log` file alongside the directory in the ManagedRepository. The import logs are deleted when the Fileset is deleted! I had mistakenly assumed that the failures would all be for similar reasons.

Can you add me to cc list of https://trac.openmicroscopy.org/ome/ticket/13251 ?

I've done that, though this ticket is specifically about the cleanse bug. I have also opened an internal card to address this class of import fail where the user specifies the wrong target id. Ideally this should result in an orphaned import rather than a failure. Once that card is moved out to a public board I'll send those details.

Thx for all the help Colin!

Thanks for your patience!

If this happens again then the simpler `fs` command,

Code: Select all

bin/omero fs sets --without-images


could be used to find those Filesets, this doesn't explicitly identify the user id though that is likely to be in the Prefix.

Cheers,

Colin

[rdecoster]

thx colin

Here's the log, I can't make up why it failed, you?

21-58-26.864.zip

log file

(914 Bytes) Downloaded 118 times

Enjoy the WE.

Cheers,
Raf

[cblackburn]

Hi Raf,

You're right, that's not much help. Thanks for posting it though, it shows that our logging should be improved in failure cases at least.

Enjoy your weekend too!

Cheers,

Colin