Import error: omero.ResourceError: null

[dsudar]

Hi all,
I started testing the inplace import functionality using hard links. Worked great with just a few files but then I got ambitious and started the import of a set of 8 ScanR-acquired plates (with 700 "wells"/images each) with a shell script as follows:

~omero_user/OMERO.server/bin/omero -s localhost -u sudar import -- --transfer=ln -r 51 -n LI8V00101_A01_04132015_PC3_PBS LI8V00101_A01_04132015_PC3_PBS_001
~omero_user/OMERO.server/bin/omero -s localhost -u sudar import -- --transfer=ln -r 51 -n LI8V00101_A02_04132015_PC3_IGF LI8V00101_A02_04132015_PC3_IGF_001
~omero_user/OMERO.server/bin/omero -s localhost -u sudar import -- --transfer=ln -r 51 -n LI8V00101_A03_04132015_PC3_bFGF LI8V00101_A03_04132015_PC3_bFGF_001
~omero_user/OMERO.server/bin/omero -s localhost -u sudar import -- --transfer=ln -r 51 -n LI8V00101_A04_04132015_PC3_10FBS LI8V00101_A04_04132015_PC3_10FBS_001
~omero_user/OMERO.server/bin/omero -s localhost -u sudar import -- --transfer=ln -r 51 -n LI8V00101_B01_04132015_PC3_PBS LI8V00101_B01_04132015_PC3_PBS_001
~omero_user/OMERO.server/bin/omero -s localhost -u sudar import -- --transfer=ln -r 51 -n LI8V00101_B02_04132015_PC3_bFGF LI8V00101_B02_04132015_PC3_bFGF_001
~omero_user/OMERO.server/bin/omero -s localhost -u sudar import -- --transfer=ln -r 51 -n LI8V00101_B03_04132015_PC3_10FBS LI8V00101_B03_04132015_PC3_10FBS_001
~omero_user/OMERO.server/bin/omero -s localhost -u sudar import -- --transfer=ln -r 51 -n LI8V00101_B04_04132015_PC3_EGF LI8V00101_B04_04132015_PC3_EGF_001

First plate went fine and then halfway through the 2nd plate I got the error:

2015-04-24 19:40:51,830 166484 [ main] INFO .importer.transfers.HardlinkFileTransfer - Transferring /data/share/lincs_user/LI8V001/LI8V00101/LI8V00101_A02_04132015_PC3_IGF_001/data/--W00257--P00001--Z00000--T00000--Alexa 555.tif...
2015-04-24 19:40:51,862 166516 [ main] INFO ormats.importer.cli.LoggingImportMonitor - FILE_UPLOAD_STARTED: /data/share/lincs_user/LI8V001/LI8V00101/LI8V00101_A02_04132015_PC3_IGF_001/data/--W00257--P00001--Z00000--T00000--Alexa 555.tif
2015-04-24 19:40:51,884 166538 [ main] ERROR ome.formats.importer.cli.ErrorHandler - FILE_EXCEPTION: /data/share/lincs_user/LI8V001/LI8V00101/LI8V00101_A02_04132015_PC3_IGF_001/data/--W00257--P00001--Z00000--T00000--Alexa 555.tif
omero.ResourceError: null
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.7.0_75]
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) ~[na:1.7.0_75]
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.7.0_75]
at java.lang.reflect.Constructor.newInstance(Constructor.java:526) ~[na:1.7.0_75]
at java.lang.Class.newInstance(Class.java:379) ~[na:1.7.0_75]
at IceInternal.BasicStream.createUserException(BasicStream.java:2615) ~[ice.jar:na]
at IceInternal.BasicStream.access$300(BasicStream.java:12) ~[ice.jar:na]
at IceInternal.BasicStream$EncapsDecoder10.throwException(BasicStream.java:3099) ~[ice.jar:na]
at IceInternal.BasicStream.throwException(BasicStream.java:2077) ~[ice.jar:na]
at IceInternal.Outgoing.throwUserException(Outgoing.java:538) ~[ice.jar:na]
at omero.api._RawFileStoreDelM.close(_RawFileStoreDelM.java:466) ~[blitz.jar:na]
at omero.api.RawFileStorePrxHelper.close(RawFileStorePrxHelper.java:1877) ~[blitz.jar:na]
at omero.api.RawFileStorePrxHelper.close(RawFileStorePrxHelper.java:1839) ~[blitz.jar:na]
at ome.formats.importer.transfers.AbstractExecFileTransfer.checkLocation(AbstractExecFileTransfer.java:118) ~[blitz.jar:na]
at ome.formats.importer.transfers.AbstractExecFileTransfer.transfer(AbstractExecFileTransfer.java:63) ~[blitz.jar:na]
at ome.formats.importer.ImportLibrary.uploadFile(ImportLibrary.java:430) [blitz.jar:na]
at ome.formats.importer.ImportLibrary.importImage(ImportLibrary.java:503) [blitz.jar:na]
at ome.formats.importer.ImportLibrary.importCandidates(ImportLibrary.java:287) [blitz.jar:na]
at ome.formats.importer.cli.CommandLineImporter.start(CommandLineImporter.java:245) [blitz.jar:na]
at ome.formats.importer.cli.CommandLineImporter.main(CommandLineImporter.java:858) [blitz.jar:na]
2015-04-24 19:40:51,888 166542 [ main] ERROR ome.formats.importer.ImportLibrary - Error on import: Cannot find path. Deleted? /data/OMERO/ManagedRepository/sudar_2/2015-04/24/19-38-50.012/data/--W00257--P00001--Z00000--T00000--Alexa 555.tif
omero.ResourceError: null
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.7.0_75]
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) ~[na:1.7.0_75]
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.7.0_75]
at java.lang.reflect.Constructor.newInstance(Constructor.java:526) ~[na:1.7.0_75]
at java.lang.Class.newInstance(Class.java:379) ~[na:1.7.0_75]
at IceInternal.BasicStream.createUserException(BasicStream.java:2615) ~[ice.jar:na]
at IceInternal.BasicStream.access$300(BasicStream.java:12) ~[ice.jar:na]
at IceInternal.BasicStream$EncapsDecoder10.throwException(BasicStream.java:3099) ~[ice.jar:na]
at IceInternal.BasicStream.throwException(BasicStream.java:2077) ~[ice.jar:na]
at IceInternal.Outgoing.throwUserException(Outgoing.java:538) ~[ice.jar:na]

and it aborted this plate. But then it aborted the next plate and next and etc... on the first file it encountered in the plate with the same exact error message.

When looking at master.err, I saw at almost the same timestamp (but ~2 minutes later ????) the following messages that appear to coincide with the aborts:

Apr 24, 2015 7:42:17 PM java.util.prefs.FileSystemPreferences checkLockFile0ErrorCode
WARNING: Could not lock User prefs. Unix error code 24.
Apr 24, 2015 7:42:17 PM java.util.prefs.FileSystemPreferences syncWorld
WARNING: Couldn't flush user prefs: java.util.prefs.BackingStoreException: Couldn't get file lock.
Apr 24, 2015 7:42:24 PM java.util.prefs.FileSystemPreferences checkLockFile0ErrorCode
WARNING: Could not lock User prefs. Unix error code 24.
Apr 24, 2015 7:42:47 PM java.util.prefs.FileSystemPreferences checkLockFile0ErrorCode
WARNING: Could not lock User prefs. Unix error code 24.
Apr 24, 2015 7:42:47 PM java.util.prefs.FileSystemPreferences syncWorld
WARNING: Couldn't flush user prefs: java.util.prefs.BackingStoreException: Couldn't get file lock.
Apr 24, 2015 7:45:17 PM java.util.prefs.FileSystemPreferences checkLockFile0ErrorCode
WARNING: Could not lock User prefs. Unix error code 24.
Apr 24, 2015 7:45:17 PM java.util.prefs.FileSystemPreferences syncWorld
WARNING: Couldn't flush user prefs: java.util.prefs.BackingStoreException: Couldn't get file lock.
Apr 24, 2015 7:45:47 PM java.util.prefs.FileSystemPreferences checkLockFile0ErrorCode
WARNING: Could not lock User prefs. Unix error code 24.
Apr 24, 2015 7:45:47 PM java.util.prefs.FileSystemPreferences syncWorld
WARNING: Couldn't flush user prefs: java.util.prefs.BackingStoreException: Couldn't get file lock.
Apr 24, 2015 7:45:49 PM java.util.prefs.FileSystemPreferences checkLockFile0ErrorCode
WARNING: Could not lock User prefs. Unix error code 24.
Apr 24, 2015 7:48:17 PM java.util.prefs.FileSystemPreferences checkLockFile0ErrorCode
WARNING: Could not lock User prefs. Unix error code 24.
Apr 24, 2015 7:48:17 PM java.util.prefs.FileSystemPreferences syncWorld
WARNING: Couldn't flush user prefs: java.util.prefs.BackingStoreException: Couldn't get file lock.
Apr 24, 2015 7:48:47 PM java.util.prefs.FileSystemPreferences checkLockFile0ErrorCode
WARNING: Could not lock User prefs. Unix error code 24.
Apr 24, 2015 7:48:47 PM java.util.prefs.FileSystemPreferences syncWorld
WARNING: Couldn't flush user prefs: java.util.prefs.BackingStoreException: Couldn't get file lock.
Apr 24, 2015 7:54:17 PM java.util.prefs.FileSystemPreferences checkLockFile0ErrorCode
WARNING: Could not lock User prefs. Unix error code 24.
Apr 24, 2015 7:54:17 PM java.util.prefs.FileSystemPreferences syncWorld
WARNING: Couldn't flush user prefs: java.util.prefs.BackingStoreException: Couldn't get file lock.

This is a CentOS 6.6 server running OMERO 5.1 and the filesystem is on local disk under ZFS.
Any pointers what this is likely caused by?
Unix error code 24 seems to point to "Too many open files" so should I increase the ulimit (or is OMERO 5.1 leaking file descriptors)? My ulimit and file-max settings are:

[inplace_user@lincs LI8V00101]$ ulimit -Hn
4096
[inplace_user@lincs LI8V00101]$ ulimit -Sn
1024
[inplace_user@lincs LI8V00101]$ cat /proc/sys/fs/file-max
6544206

Or might there be an issue with ZFS not providing proper file locking?

When after dinner I came back and ran the same plate that was the first to fail again, it imported just fine. So it wasn't anything specific to that plate.

Thanks for all advice.
- Damir

[dsudar]

And a quick follow-on: After importing my plate #2 successfully, I immediately started the import of my plate #3 in the list and bang, at the exact same spot in the plate import sequence (at image #257, 3rd channel image) it aborted that with the same error. So clearly I'm hitting some fairly precise limit.
- Damir

[dsudar]

Sorry for the piece-meal reporting but after a good night sleep and a new determination to get those plates imported somehow, I just went back to the good old ways without the inplace hardlink transfer method. So I modified my little script to take out the "-- --transfer=ln" section and it's now running perfectly fine plate after plate after plate. So my current thinking is: there is a bug in the inplace import (at least when using hard links) where it doesn't release file descriptors (or at least not quick enough) and so it runs out of fd's when the ulimit is reached. And increasing the ulimit would only be a delay of execution so not the right way to deal with this issue. Does that sound right? Anything I can try or test to help you guys get at this bug?

Thanks,
- Damir

PS. Completely unrelated but currently the upgrade check seems to be failing every time. Is that server offline?
I get this when running the import:

2015-04-25 12:32:49,189 40930 [ main] ERROR ome.system.UpgradeCheck - Error reading from url: http://upgrade.openmicroscopy.org.uk?ve ... orporation "Server returned HTTP response code: 504 for URL: http://upgrade.openmicroscopy.org.uk?ve ... orporation"

[jmoore]

Hi all,
I started testing the inplace import functionality using hard links. Worked great with just a few files but then I got ambitious and started the import of a set of 8 ScanR-acquired plates (with 700 "wells"/images each) with a shell script as follows:
...

First plate went fine and then halfway through the 2nd plate I got the error:

Code: Select all

2015-04-24 19:40:51,888 166542     [      main] ERROR        ome.formats.importer.ImportLibrary - Error on import: Cannot find path. Deleted? /data/OMERO/ManagedRepository/sudar_2/2015-04/24/19-38-50.012/data/--W00257--P00001--Z00000--T00000--Alexa 555.tif
omero.ResourceError: null


...
and it aborted this plate. But then it aborted the next plate and next and etc... on the first file it encountered in the plate with the same exact error message.
...

This is a CentOS 6.6 server running OMERO 5.1 and the filesystem is on local disk under ZFS.
Any pointers what this is likely caused by? Unix error code 24 seems to point to "Too many open files" so should I increase the ulimit (or is OMERO 5.1 leaking file descriptors)? My ulimit and file-max settings are:

Code: Select all

[inplace_user@lincs LI8V00101]$ ulimit -Hn
4096
[inplace_user@lincs LI8V00101]$ ulimit -Sn
1024
[inplace_user@lincs LI8V00101]$ cat /proc/sys/fs/file-max
6544206


What's the limit for the server user? In general, 1024 is not going to be enough, so if that's the value for the server user too, I'd be interested to see how much farther we can get with a more reasonable value, say 8k.

And a quick follow-on: After importing my plate #2 successfully, I immediately started the import of my plate #3 in the list and bang, at the exact same spot in the plate import sequence (at image #257, 3rd channel image) it aborted that with the same error. So clearly I'm hitting some fairly precise limit.

...

Sorry for the piece-meal reporting but after a good night sleep and a new determination to get those plates imported somehow, I just went back to the good old ways without the inplace hardlink transfer method. So I modified my little script to take out the "-- --transfer=ln" section and it's now running perfectly fine plate after plate after plate. So my current thinking is: there is a bug in the inplace import (at least when using hard links) where it doesn't release file descriptors (or at least not quick enough) and so it runs out of fd's when the ulimit is reached. And increasing the ulimit would only be a delay of execution so not the right way to deal with this issue. Does that sound right? Anything I can try or test to help you guys get at this bug?

Most helpful would be a list of the files when the errors start occurring:

Code: Select all

  lsof -p $(bin/omero admin ice server pid Blitz-0)


PS. Completely unrelated but currently the upgrade check seems to be failing every time. Is that server offline?
I get this when running the import:

Code: Select all

2015-04-25 12:32:49,189 40930      [      main] ERROR                   ome.system.UpgradeCheck - Error reading from url: http://upgrade.openmicroscopy.org.uk?version=5.1.0-ice35-b40;os.name=Linux;os.arch=amd64;os.version=2.6.32-504.12.2.el6.x86_64;java.runtime.version=1.7.0_75-mockbuild_2015_01_20_23_39-b00;java.vm.vendor=Oracle+Corporation "Server returned HTTP response code: 504 for URL: http://upgrade.openmicroscopy.org.uk?version=5.1.0-ice35-b40;os.name=Linux;os.arch=amd64;os.version=2.6.32-504.12.2.el6.x86_64;java.runtime.version=1.7.0_75-mockbuild_2015_01_20_23_39-b00;java.vm.vendor=Oracle+Corporation"


Thanks for letting us known, but checks are working for me in Germany. You're seeing these in the import logs? Are they still happening? Could some firewall be preventing the check?

Cheers,
~Josh

[dsudar]

Hi Josh,

First I ran it without changing the ulimit (indeed I have the same ulimits for "omero_user") to generate the lsof list per:

Most helpful would be a list of the files when the errors start occurring:
lsof -p $(bin/omero admin ice server pid Blitz-0)

It's a pretty long listing so I'm uploading to the QA system: #11042

Next I'll try to increase the ulimit and see where that gets me. So set soft limit to 8192 and hard limit to 32k or so?

The upgrade check is still failing and indeed shows up in the import log. Could indeed be a firewall issue. Is that using port 80 outbound? Not a biggy.

Thanks,
- Damir

[jmoore]

First I ran it without changing the ulimit (indeed I have the same ulimits for "omero_user") to generate the lsof list per:

Most helpful would be a list of the files when the errors start occurring:
lsof -p $(bin/omero admin ice server pid Blitz-0)

It's a pretty long listing so I'm uploading to the QA system: #11042

Got it. Thanks. The listing certainly doesn't look reassuring. I'll keep trying to reproduce on my side and will get back to you for any other specifics.

Next I'll try to increase the ulimit and see where that gets me. So set soft limit to 8192 and hard limit to 32k or so?

That should certainly work. I wouldn't think you'd ever need to go to 32K; a "big install" might want to start with say 16K.

The upgrade check is still failing and indeed shows up in the import log. Could indeed be a firewall issue. Is that using port 80 outbound? Not a biggy.

That should just be 80/outbound, yup.
~Josh.

[jmoore]

Hi Damir,

I found a fix for the dangling file handles and opened pull request 3763 which should go into 5.1.2 towards the end of the month. There exists a workaround, namely to close the session used to import each plate. On session close, all the remaining file handles will be released.

Thanks for helping to track this down!
~Josh.

[dsudar]

Hi Josh,

Thanks for figuring it out. Okay, for now I can close the session after each plate and I will still increase the ulimit quite a bit. Considering the default ulimits on CentOS 6 (and Ubuntu 12.04) are relatively low, maybe good to mention that in the installation instructions. I did notice it mentioned in the "Known limitations" and "Troubleshooting" sections.

Interesting that this issue with the file handles sticking around only manifested itself with inplace imports and not when doing the regular copy-imports.

Back to the upgrade check failures in the import log: they still occur and I verified that my server can reach out over port 80 to http://upgrade.openmicroscopy.org.uk . If I visit the entire URL as in the error in the log using the lynx web browser, it appears to redirect to: http://www.openmicroscopy.org/site/supp ... Check.html

Cheers,
- Damir

[jmoore]

Hi Damir,

Back to the upgrade check failures in the import log:

Indeed. Sorry for the long wait.

they still occur and I verified that my server can reach out over port 80 to http://upgrade.openmicroscopy.org.uk . If I visit the entire URL as in the error in the log using the lynx web browser, it appears to redirect to: http://www.openmicroscopy.org/site/supp ... Check.html

Only a call with the right agent will not redirect to `UpgradeCheck.html`. Can you try this:

Code: Select all

curl -LA OMERO.test "http://upgrade.openmicroscopy.org.uk/?version=5.1.0-ice35-b40;os.name=Linux;os.arch=amd64;os.version=2.6.32-504.12.2.el6.x86_64;java.runtime.version=1.7.0_75-mockbuild_2015_01_20_23_39-b00;java.vm.vendor=Oracle+Corporation"


which is the URL from your post above. For me it shows:

Code: Select all

Please upgrade to 5.1.1...


Cheers,
~Josh.