Download cache gets confused in parallel (using shell bg / GNU parallel / SLURM / etc)

Description

I'm running astropy on an offline computer. I need the added accuracy that the de430 ephemerides provide, and so at the beginning of the utility, I call

astropy.coordinates.solar_system_ephemeris.set('file://path/to/local/copy/de430.bsp')

Sometimes, I'm in a hurry to get things done, and so I'll fire off multiple copies of my utility from the shell (use moar cores!), and the processes will often (but not always) will decide that the file is out of date and start copying it ("downloading") from the path above into /tmp, start fighting over the lock for the cache directory, then barf, etc. I end up with most of my runs failed, a /tmp directory full of abandoned files, and a bunch of frustration.

I have discovered that if I set XDG_CACHE_HOME to a directory that is mounted locally (/tmp is my only option) instead of through NFS, I can no longer trigger the bug. I assume that the lock is assuming file existence is atomic, near as I can tell NFS only guarantees directory creation to be an atomic operation.

Expected behavior

I expected the file to be "downloaded" at most once and everyone else to wait their turn.
I would prefer that there were a way to disable downloading/caching entirely (perhaps similar to how the IERS util in astropy allows pointing at a local finals2000a.all)

Actual behavior

   File "/usr/local/lib/python2.7/dist-packages/astropy/coordinates/solar_system.py", line 175, in _get_kernel
    return SPK.open(download_file(value, cache=True))
  File "/usr/local/lib/python2.7/dist-packages/astropy/utils/data.py", line 1122, in download_file                   _acquire_download_cache_lock()
  File "/usr/local/lib/python2.7/dist-packages/astropy/utils/data.py", line 1405, in _acquire_download_cache_lock
    raise RuntimeError(msg.format(lockdir))
RuntimeError: Unable to acquire lock for cache directory (/home/mcbeth/Sites/astropy/download/py2/lock exists). You may need to delete the lock if the python interpreter wasn't shut down properly.

Steps to Reproduce

#!/usr/bin/env python

import astropy.coordinates as coords
from astropy.time import Time

coords.solar_system_ephemeris.set('file:///home/mcbeth/astropy_caching/de430.bsp')
print(coords.get_sun(Time.now()))

for x in {0..100}; do
  ./caching_test.py&
done

mkdir /tmp/astropy
export XDG_CACHE_HOME=/tmp
for x in {0..100}; do
  ./caching_test.py&
done

System Details

Linux-5.0.0-32-generic-x86_64-with-Ubuntu-19.10-eoan
Python 3.7.5rc1 (default, Oct 8 2019, 16:47:45)
[GCC 9.2.1 20191008]
Numpy 1.16.2
Scipy 1.2.2
astropy 3.2.1

@mcbeth

@mcbeth , given that the caching mechanism was overhauled in 4.0 (currently in pre-release stage) via #9182, are you able to confirm that this is still the behavior you see with astropy 4.0rc1?

On 4.0rc1, I get the warning
WARNING: leap-second auto-update failed due to the following exception: RuntimeError('Cache is locked after 5.01 s. This may indicate an astropy bug or that kill -9 was used. If you want to unlock the cache remove the directory
/home/mcbeth/Sites/astropy/download/py3/lock. Lock claims to be held by process 19832.') [astropy.time.core]

It appears that all the runs completed, so this is at least progress.

@mcbeth

@mcbeth , so it does sound like a race condition in the cache in parallel processing. Since you are able to run your code to completion in 4.0rc1, this is no longer an issue when 4.0 is released?

I need to take that back. I just tried on a much beefier machine, and of the 101 cases, only 39 completed. The rest failed with

Traceback (most recent call last):
  File "./caching.py", line 6, in <module>                                                                            coords.solar_system_ephemeris.set('file:///home/mcbeth/astropy_caching/de430.bsp')
  File "/home/mcbeth/astropy_caching/experiment/lib/python3.7/site-packages/astropy/utils/state.py", line 68, in s
et                                                                                                                    value = cls.validate(value)
  File "/home/mcbeth/astropy_caching/experiment/lib/python3.7/site-packages/astropy/coordinates/solar_system.py",
line 115, in validate                                                                                                 cls.get_kernel(value)
  File "/home/mcbeth/astropy_caching/experiment/lib/python3.7/site-packages/astropy/coordinates/solar_system.py",
line 126, in get_kernel                                                                                               kernel = _get_kernel(value)
  File "/home/mcbeth/astropy_caching/experiment/lib/python3.7/site-packages/astropy/coordinates/solar_system.py",
line 179, in _get_kernel                                                                                              return SPK.open(download_file(value, cache=True))
  File "/home/mcbeth/astropy_caching/experiment/lib/python3.7/site-packages/astropy/utils/data.py", line 1186, in
download_file                                                                                                         pkgname=pkgname)
  File "/home/mcbeth/astropy_caching/experiment/lib/python3.7/site-packages/astropy/utils/data.py", line 1819, in
import_file_to_cache                                                                                                  with _cache(pkgname, write=True) as (dldir, url2hash):
  File "/usr/lib/python3.7/contextlib.py", line 112, in __enter__
    return next(self.gen)                                                                                           File "/home/mcbeth/astropy_caching/experiment/lib/python3.7/site-packages/astropy/utils/data.py", line 1642, in
_cache
    shelve.open(urlmapfn, flag="c") as url2hash:                                                                    File "/usr/lib/python3.7/shelve.py", line 243, in open
    return DbfilenameShelf(filename, flag, protocol, writeback)
  File "/usr/lib/python3.7/shelve.py", line 227, in __init__                                                          Shelf.__init__(self, dbm.open(filename, flag), protocol, writeback)
  File "/usr/lib/python3.7/dbm/__init__.py", line 94, in open
    return mod.open(file, flag, mode)                                                                             _gdbm.error: [Errno 11] Resource temporarily unavailable

@aarchiba

Just to satisfy my academic curiousity, on this beefier machine using astropy 4.0rc1... What if before you do the parallel run, you manually do a download_file(...) call to make sure the file is first cached? Then, theoretically, with cache=True in the solar_system call, it shouldn't try to overwrite the cache? 🤔

Maybe @aarchiba has a better idea.

I'm sorry, I can't find the call that accepts cache=True as a parameter, and I'm only making two calls in my minimal case

I was just reading your traceback:

astropy/astropy/coordinates/solar_system.py

Line 179 in 918abcd

return SPK.open(download_file(value, cache=True))

Hmm. Some of these problems were things I thought should not occur, others are ones I expected but are unfortunate anyway. I can suggest workarounds.

What's going on?

First: in 4.0rc1, the cache locking mechanism assumes only that directory creation is atomic, so it should work on NFS. But there are caveats:

There is a timeout, defaulting to (I think) 5 seconds, after which any given process will give up on obtaining the cache lock. Mostly this will fail with an exception, but in some cases you get an un-cached download (so the program will work but with a download). Any given process will hold this lock for a fairly short time and then release it (although a kill -9 can leave the lock held). But if enough processes are trying to use the cache, and especially if the cache is over NFS so that file operations are slower (and atomic file operations are very slow) you can start getting timeouts.
File downloading peeks into the cache once up front to see if the file is already there. Then it releases the lock. If the file isn't present, the download proceeds without the lock being held. Once the file has been obtained, the downloader tries to obtain the lock again. If it succeeds and the file is still absent, it's copied into place. If the file is present already the second downloaded version is discarded. The lock is released, and in these cases, the downloaded file is returned to the calling process. If the lock cannot be obtained (perhaps because a bazillion processes are hammering at it), a warning is emitted and the freshly downloaded version is returned without copying into the cache. So either way you should get access to the file, but it may get downloaded multiple times unnecessarily.

You should no longer ever see messages about gdbm and resources unavailable; that is a sign that something has gone wrong with the locking mechanism. I have some tests that are supposed to hammer the local machine and attempt to trigger this, I can run them with greater stress and see if I can find and debug this case.

What can you do?

There are a number of tools you can use to address this.

Most easily you can increase the number of tries (actually a timeout now) to obtain the cache lock. This is set in the astropy config file. Of course, this means your moar cores are waiting for each other to unlock the cache, so that's not optimal.
You can have each process use a separate cache and obtain the file from a single location (say a local file you have downloaded already) and import into every process' cache individually. If the caches aren't shared, there won't be lock conflicts. If they are modestly shared but not over NFS (say all eight processes on one machine share a cache under /tmp) the lock conflicts shouldn't be much of a problem.
You can explicitly download the file up front and then share the cache between multiple machines. If you know which file you need - in fact I think you have downloaded it already - you can just do a download_file(url, cache=True, sources=["file:///path/to/file"]) on one core and it will sit in the cache and persist indefinitely. Then any machine that shares that cache will not need to download it again. This makes sense if you have an NFS-shared cache, or can set one up with XDG_CACHE_HOME.
You can pre-load the cache with everything you need, again in a single process, then use the export cache functionality to dump it to a zip file. Then each process can have its separate cache and use import to load up the whole pre-downloaded cache. This was in fact designed for machines that need disconnected operation.

A final note

Objects in the cache are indexed by URL, ideally the URL on the net where the authoritative version lives. the solar_system call is a shortcut that just tries to download it from there, but if you use download_file(URL, cache=True, sources=[...]) you can obtain the file from any of a list of alternative locations, which can be local files, and it will be indexed under the official URL (and so will be picked up the the solar_system call later).

Also worth noting, astropy is supposed to delete its temporary downloads in an atexit call but this is not easy to test and so it may leave some stranded. But such persist-until-exit files only exist if the cache is not being used (because it was not wanted or because some locking problem made it fail).

I'm sorry, I can't find the call that accepts cache=True as a parameter, and I'm only making two calls in my minimal case

If you are trying to nail down the cache misbehaviour, then first of all thank you! And second the key function is download_file, which provides the most granular control over file downloading. So if you want to make a minimal example that's a good place to start. Again, thank you! Obviously I need to find a chance to stress this more thoroughly on a cluster.

There is a minimal example up at the top :)
In all of the cases where I've reported, the cache was already pre-filled with the correct and up to date data. On Astropy 3.2.1, I'm seeing the caching system decide to go download again anyway (from my predownloaded file), and then they start churning and then crashes.

I'm not going to be able to dig in to 4.0rc1 for a bit because I tried to test the new 4.0rc1 capability (#8767) for me to hand it a file rather than a file-url (yeah!!!1!), and have managed to knock the beefier machine off my internal network. The one thing I saw before things went down was that there still was lock contention (that really surprised me, as isn't the lock stuff all within download_file instead of above _get_kernel?)

@eteq

Maybe @eteq or @adrn have ideas too on how caching/offline use can be improved on the solar_system side.

There is a minimal example up at the top :)

So, uh, I was thinking minimal in terms of moving parts - just to make sure solar_system isn't doing anything weird. You could just put download_file(url, cache=True) with the same URL you use above and the same behaviour should occur - if it doesn't something strange is going on in solar_system.

In all of the cases where I've reported, the cache was already pre-filled with the correct and up to date data. On Astropy 3.2.1, I'm seeing the caching system decide to go download again anyway (from my predownloaded file), and then they start churning and then crashes.

It's hard for me to say much about Astropy 3, but I think it had the same behaviour - if the lock wasn't available it would time out and be unable to use the cache and as a result fall back to downloading ("downloading" from the local URL you provided) anew. You should get a CacheMissing warning in this case. Also Astropy 3 didn't try very hard to acquire the cache (just 5 times one second apart) before giving up.

The old locking mechanism used NFS as well but was not as reliable - and there were cases where it did not acquire the lock but it needed to because gdbm requires write access to be exclusive.

I'm not going to be able to dig in to 4.0rc1 for a bit because I tried to test the new 4.0rc1 capability (#8767) for me to hand it a file rather than a file-url (yeah!!!1!), and have managed to knock the beefier machine off my internal network. The one thing I saw before things went down was that there still was lock contention (that really surprised me, as isn't the lock stuff all within download_file instead of above _get_kernel?)

I don't know what lives in solar_system but maybe when you pass it a file it tries to save that file in the cache? Because yeah only astropy.utils.data uses the cache locking directly at all. Everything else passes through that module and probably through download_file specifically.

Fix bug in locking mechanism

Thank you for the bug report - there is a bug in 4.0 where if the cache lock cannot be obtained, it raises an exception - but then removes the lock. So then you get contention for the underlying shelve object and Bad Things happen. There is a fix in #9669.

You will still have headaches as long as the lock lives on NFS, because locking and unlocking is slow and painful, so that you will have delays over lock contention if you use an NFS-shared cache with many processes trying to access it. But it should now uniformly raise an exception and stop if the lock cannot be acquired rather than doing anything unpredictable. You can increase the timeout if you like. But it's probably better to use a non-shared cache, preferably not over NFS.

I think the chances of this being fixed in pre-4.0 are very remote - the cache locking mechanism was basically a non-functional mess but revamping it was a big job and backporting that is not feasible. But again, using a non-shared cache will solve that problem, and if you are "downloading" the file from a local URL that's not hard to arrange.

Fix bug in locking mechanism

I'll be looking at moving to a non-shared cache (as work won't be moving to 4.0, probably until a new leap second occurs), but that is hardly trivial (we're typically working in a shared workspace with a single username on multiple machines using multiple processes to complete the embarassingly parallel work). I would much rather be pointing it at a file rather than an URL and skip the caching all together, on 4.0rc1, I still hit cache lock errors even pointing it at a file. I haven't been able to properly test #9699 as my personal NFS server crapped the bed last night while testing, and my work environment requires an act of God and Congress to install software (especially experimental).

If you do have to use a shared cache, setting the number of retries in the config file higher should reduce the suffering. Pre-4.0, the cache lock was tried only this many times, a second apart - exactly a second, so if N processes started up and crashed into the lock, one would get it, and N-1 would wait exactly a second and then all retry. The new code is better now that I have fixed the accidental unlocking bug.

In terms of the cache, using a "file://..." URL versus an "http://..." URL should be equivalent in terms of locking (but of course the file is faster to obtain if it is ever downloaded). If the file is already in the cache, though, with 4.0 (with PR #9669) the two possible outcomes should be (a) use the file in the cache, or (b) raise an exception because you couldn't acquire the lock. In principle pre-4.0 should simply use the existing file in the cache but when there is contention for the database (which is not always accessed through the lock) you might end up with the code falling through to a re-download.

If the solar system code has an option to load a file directly avoiding the cache, I don't know how that works but if it does it seems like the locking should not enter into the equation at all. It might be implemented by using a file:// URL, though.

@mcbeth

@mcbeth , when you get the chance to use astropy 4.0 or later, and this is still a problem, please report in a new issue. Thanks!

Let me add a couple of final suggestions:

Try making the (pre-loaded) cache read-only. On 4.0 it will avoid any locking. On earlier versions, maybe?
There are three modules that the cache can use, dbm.dumb, dbm.ndbm, and dbm.gdbm. Under pre-4.0 these may have different contention behaviour, and one of them may be preferable to the others. Unfortunately it's a bit of a nuisance to choose which one the cache uses, but it can be done.

Fix bug in locking mechanism

Navigation Menu

Repository navigation

Download cache gets confused in parallel (using shell bg / GNU parallel / SLURM / etc) #9642

Description

Expected behavior

Actual behavior

Steps to Reproduce

System Details

What's going on?

What can you do?

A final note

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Download cache gets confused in parallel (using shell bg / GNU parallel / SLURM / etc) #9642

Description

Description

Expected behavior

Actual behavior

Steps to Reproduce

System Details

Activity

pllim commented on Nov 21, 2019

mcbeth commented on Nov 22, 2019

pllim commented on Nov 22, 2019

mcbeth commented on Nov 22, 2019

pllim commented on Nov 22, 2019

mcbeth commented on Nov 22, 2019

pllim commented on Nov 22, 2019

aarchiba commented on Nov 22, 2019

What's going on?

What can you do?

A final note

aarchiba commented on Nov 22, 2019

aarchiba commented on Nov 22, 2019

mcbeth commented on Nov 22, 2019

pllim commented on Nov 22, 2019

aarchiba commented on Nov 23, 2019

aarchiba commented on Nov 25, 2019

aarchiba commented on Nov 25, 2019

mcbeth commented on Dec 3, 2019

aarchiba commented on Dec 4, 2019

pllim commented on Dec 4, 2019

aarchiba commented on Dec 5, 2019

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions