Concurrency issues with package cache in validator #1641
Comments
|
The information in this file is only used when displaying the cache to a user and advising when an entry in the cache was last used. There is a tool that does this, but not all tools set the usage date, so it's not reliable. We should surround this code with a try..catch and ignore any errors from it; they simply don't matter. |
|
Update: there is one other error we've seen multiple times, looks like it's related to one thread trying to read a file while another is trying to delete it. I haven't had time to try to replicate this yet but this is the log snippet. |
|
Yes this is. big concurrency issue. scheduled to look at next week |
|
I've done some initial work with this. I created I have the beginnings of a solution, which gets me repeated passes for master...do-20240722-thread-safety The issue is that there is no read lock... we check to make sure two engines aren't writing the same data, but never that one engine might be reading something that is still in the process of being written. What I've done in the branch above is first ask for another write lock when we need to read. Then, if a write lock is permitted (no one is writing), the lock is downgraded to a read. There are multiple read threads allowed on these locks, but just one write, so this will give us a bit more efficiency, rather than only allowing a single thread to read at a time. This is by no means a complete solution, just something to start with. Thoughts? |
|
Hah, and I see that there's some DDOS protection on the server, because my repeated tests are displaying 'Too Many Requests' errors. |
|
Oh... and this is weird. Dylan's test STILL fails, but for a different reason; the txCache is getting repeatedly cleared because at some point |
|
Thanks @dotasek , I haven't dug into the details of how files get read here, but conceptually this sounds good. One thought though - it sounds like the issue is more that there currently is no read-locking being done, rather than an existing read-lock mechanism is broken. Is the always-get-a-write-lock-to-read-lock approach needed? Since the write lock is exclusive, seems like that will result in read locks essentially being made exclusive too |
|
@dehall I'm thinking along similar lines. I ran this several times this morning only to get different failures for other files, which have no locks on them at all. The lock downgrade mechanism actually releases the write lock, so it doesn't make read locks exclusive. It gets a write lock, then gets a read lock, then releases the write lock, leaving only the read lock active while it does its work. The intent there was to prevent reads while writing is happening. This should work OK for the package manager, where it only writes a file once. I do have to check if there's a case where certain files will be re-written; I'm thinking particularly packages.ini And, looking at how the terminology cache works, this concurrency will likely be a big issue there, and a more complex one, because the cache appends to files instead of just creating and writing once. |
|
Some very odd errors cropping up today that I don't recall seeing before: I don't know if this is related to concurrency at all. Even reverting to a state before my changes results in this behaviour. |
|
To get beyond the issue I was experiencing, I started running my test using local packages, so at least I'm not hammering the package server as much. I made some changes that seem to get @dehall 's test to repeatedly pass (I set it to loop until failure in IntelliJ, and got to 4 before writing this). The main changes were ensuring that there's only one lock management system per package cache directory, and adding a special lock for changes to the whole package cache directory (and, I guess, the package.ini file). This is NOT in any way complete. There's so many other places it could crap out, and I removed the Dylan, could you take a look at this and see if what I did makes any sense? |
|
Sure thing, will take a look tomorrow AM. Thanks so much for digging into this |
|
No problem. This is a good find, and the replicable test is great. Staring at this now, I realize that maybe that bit of 'cleverness' with lock downgrading isn't so clever. I think it will wait for read locks to be released before allowing a write lock, so functionally, I might as well just have a write lock there. I'll need to revisit that. |
|
Overall I think this makes sense but that's with the caveat that I haven't looked at the existing and surrounding code nearly as much as you and Grahame have, and I'm not an expert in concurrency. In terms of the specifics of the locks, from reading the docs on ReadWriteLock https://docs.oracle.com/javase/8/docs/api/java/util/concurrent/locks/ReadWriteLock.html the write lock is completely exclusive but multiple read locks may be held at the same time - that sounds good. So in I'm wondering if this "Manager" approach, where a function is passed into the Manager to call after acquiring the lock, is the best way to do this. Another way to do it might be to pass the Lock around into the specific methods that do file operations and let them get the readLock or writeLock as appropriate. That way the caller doesn't have to know the specifics of what the method is going to do. But that may be a major refactoring and more trouble than it's worth |
|
I think I spoke entirely too soon. I'm looking at it again today, and I think yesterday I got the cache into a 'lucky' state. I'm getting all sorts of errors now.
This is kind of the problem with the cache; it mixes reading and writing in numerous locations instead of clearly distinguishing between the two. I think sorting THAT out first might make concurrency much easier to solve. What disturbs me about taking another approach (passing locks around) is precisely that read/write locking would be left up to individual methods. The moment we do that, we'll end up with |
Definitely agree. If the methods can be cleanly split out then the specifics of the locking approach don't matter as much. |
|
After talking with Grahame, we agreed on a few things to make this easier. There are two tracking mechanisms which are unused: usage.ini (ironically) is completely unused to date. It can be totally removed. packages.ini was also slated for total removal, except that it contains the cache version. This is important; if we update the cache implementation, this is the mechanism that allows us to identify obsolete caches and initiate a cleanup. However, the tracking mechanism for package install timestamps is totally unused, and THAT was causing file rewrites mid package install. I will remove that. I'm going to try to do two things:
|
|
The last round of commits to this branch are pretty much what I outlined in my last comment: master...do-20240722-thread-safety Still to be done:
|
This comment was marked as outdated.
This comment was marked as outdated.
|
I hid the last comment, as it was too soon. I have a consistently failing Windows test now that can't delete the lock files for some reason. Will try to fix... |
|
Apologies, I didn't have time to take a close look at this today as I'm wrapping a lot of things up before I go on vacation (back 8/28). At a glance the tests look good. Maybe I'm missing something but I don't see much in terms of new Exceptions. "Error reading package" and "Timeout waiting for lock file deletion" I think are fine. More specific exceptions for situations like this are tough because if you could explain to the user exactly what broke you could potentially handle it anyway. When you're ready for a stress test, let me know and we (the Inferno team) can try it out in the scenario we've seen this in. It doesn't happen 100% of the time but it happens often enough that we could tell pretty quickly if it's resolved |
|
@dehall I'm not ready for a stress test; unfortunately. The Ubuntu tests are failing, and I don't know why. Windows and Mac both appear to be working just fine, but I think I may have to debug in WSL or something to find out what's going on. |
When multiple validator sessions are starting up at the same time we've seen Exceptions that appear to be concurrency issues when reading from certain files in the package cache.
Similar to #1491 - this issue was initially observed using the org.hl7.fhir.validator-wrapper but able to reproduce just with the core validation library.
An example stack trace:
In practice with the validator-wrapper, I seem to recall other files causing issues but maybe it's only usage.ini. Other examples:
I suspect the issue is that
FilesystemPackageCacheManager.loadPackageInfowrites to the file without locking it, so another thread can enter this at the same time and catch the file before the first thread is done with it. It may be as simple as wrapping the following line in aFilesystemPackageCacheLock.doWriteWithLockblock but my initial attempts to do that just got me different errors.org.hl7.fhir.core/org.hl7.fhir.utilities/src/main/java/org/hl7/fhir/utilities/npm/FilesystemPackageCacheManager.java
Line 264 in ad31f71
Sample code that (usually, not always unfortunately) reproduces the issue:
The text was updated successfully, but these errors were encountered: