ConcurrentModificationException FileManager::saveToFile

[julianknutsen]

Description

BallotList is not thread-safe, but is used by the FileManager to persist to disk. All users that extend
PersistableList can have the same race condition.

Regression: No

Dec-05 13:50:46.954 [Save-file-task-9892] ERROR b.common.storage.FileManager: Error at saveToFile, storageFile=/home/julian/.local/share/Bisq/btc_mainnet/db/BallotList java.lang.RuntimeException: java.util.ConcurrentModificationException
	at bisq.common.storage.FileManager.saveToFile(FileManager.java:200)
	at bisq.common.storage.FileManager.lambda$new$0(FileManager.java:83)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.util.ConcurrentModificationException: null
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1660)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:578)
	at bisq.core.dao.state.model.governance.BallotList.getBuilder(BallotList.java:62)
	at bisq.core.dao.state.model.governance.BallotList.toProtoMessage(BallotList.java:55)
	at bisq.core.dao.state.model.governance.BallotList.toProtoMessage(BallotList.java:36)
	at bisq.common.storage.FileManager.saveToFile(FileManager.java:194)
	... 6 common frames omitted

Version

v1.2.4
v1.2.3 as well

Steps to reproduce

Only seen it once when trying to reproduce

1. Clear local appData
2. ./bisk-desktop
3. See stack trace in logs

See comments for patch that can be applied to v1.2.3 to cause bug.

Expected behaviour

All data structures used with FileManager are thread-safe

Actual behaviour

Some data structures used with FileManager are not thread-safe

Screenshots

Device or machine

Ubuntu 19.10

Additional info

bisq.log

[julianknutsen]

It looks like BallotListService passes in an unsafe object to the storage code:

BallotList contains ArrayList<T>

The onChanged() handler persists to a file after every new object which on a fresh install means a lot of changes quickly in sequence. If the List changes out from underneath the FileManager I believe this error will occur.

Here is the offending code that updates while iterating:

    public protobuf.BallotList.Builder getBuilder() {
        return protobuf.BallotList.newBuilder()
                .addAllBallot(getList().stream()
                        .map(Ballot::toProtoMessage)
                        .collect(Collectors.toList()));
    }

Confirmed the bug on v1.2.3 to show it wasn't a regression. The following patch causes the bug to happen:

@@ -58,7 +58,14 @@ public class BallotList extends PersistableList<Ballot> implements ConsensusCrit
     public protobuf.BallotList.Builder getBuilder() {
         return protobuf.BallotList.newBuilder()
                 .addAllBallot(getList().stream()
-                        .map(Ballot::toProtoMessage)
+                        .map(ballot -> {
+                            try {
+                                Thread.sleep(10);
+                            } catch (InterruptedException e) {
+                                e.printStackTrace();
+                            }
+                            return ballot.toProtoMessage();
+                        })
                         .collect(Collectors.toList()));
     }

I also found this comment in AddressEntryList that seems to have found this issue before. But, the way it solves the problem isn't thread-safe either because the ArrayList constructor is not thread-safe. It is actually worse than that because modifies-while-creating won't even throw an exception.

        // We clone list as we got ConcurrentModificationExceptions
        List<AddressEntry> clone = new ArrayList<>(list);

[julianknutsen]

I went through and audited all the users to figure out the best way to solve this in the short and long term. Here are the current users of the FileManager and the data structures they use when iterating for persistence.

Likely Unsafe
BallotList - PersistableList & ArrayList
PeerList - PersistableList & ArrayList
NavigationPath - ArrayList
PreferencesPayload - ArrayList/HashMap
UserPayload - ArrayList/HashSet
AddressEntryList - Clones into new ArrayList (unsafe)

Likely Safe
AccountAgeWitnessStore - MapStoreService & ConcurrentHashMap
BlindVoteStore - MapStoreService & ConcurrentHashMap
ProposalStore - MapStoreService & ConcurrentHashMap
SignedWitnessStore - MapStoreService & ConcurrentHashMap
TempProposalStore - MapStoreService & ConcurrentHashMap
TradeStatistics2Store - MapStoreService & ConcurrentHashMap
SequenceNumberMap - ConcurrentHashMap

Unknown
*DaoStateStore - LinkedList (only used for clone at startup?)

[chimp1984]

DaoStateStore is stored at each snapshot (each 20 blocks) as well as at sync (resync). So I assume it has the same issue. What would you recommend to fix the issues? Using concurrent lists/maps?

[julianknutsen]

I spent the afternoon running some tests and profiling the impact of a few ways to handle this. I wanted to share the options I came up with to get some feedback from others who may have encountered this in the past or have thought about it for more than a few hours.

Use concurrent data structures

Replace all data structures with their concurrent options. ArrayList -> CopyOnWriteArrayList & HashMap -> ConcurrentHashMap

This will fix the immediate problem by ensuring that during iteration a change in the underlying data structure won't cause an exception. But, there are two issues to consider:

First, CopyOnWriteArraySet is only efficient for read-heavy workloads. Since there is typically one write per read (iterating and persist) there would be a costly performance penalty when the COWAL has to copy the array on write/update/remove. This may be a non-issue because the data sets are so small, but something to consider.

Second, the real problem is that the FileManager is running arbitrary methods (toProtoMessage()) from non-UserThread without any synchronization or safety from the Storage classes. Even if we fix up all these current issues they will just reappear in a different form if it isn't fixed in a more sustainable way. It is really non-obvious which class members need to be thread-safe and which ones don't.

Create protobuf objects on the UserThread instead of the FileManager writer thread

This seems like the cleanest design moving forward. Current and future Store objects don't need to care about thread safety.

The FileManager is easier to reason about as well since the work queue AtomicReference would just store the immutable protobuf object instead of a class instance that can change.

But, the overhead for building the protobuf message on each save is pretty significant. On average, it takes around 1500ms for DaoStateStore::toProtoMessage() to complete. This negates a lot of the batching work that the FileManager hoped to accomplish and can cause the initial dao rebuild to take quite a while.

Hybrid solution

There may be a hybrid solution where we don't generate protobuf messages on the UserThread unless we are immediately shipping it off to the work queue. I think this would bring back some of the batching gains, but I don't have that data yet.

Additionally, it might make sense to just whitelist the really expensive persistent objects, roll our own synchronization, and find a way for "most" users to not care which would guarantee correctness and allow profiling to determine where to optimize instead of bugs.

[chimp1984]

Thanks for looking into it. It is a tricky topic....

If mapping to Userthread we are thread safe but we lose a part of the threading benefits, specially for frequent writes (sequence number,...) as the mapping itself takes time and if the protof conversion is expensive we get the UI stuck for that moment.

I think its probably best to first analyse which objects cost a lot of cpu time for the protobuffer conversion (DaoState, TradeStatistics, AccountAgeWitness are likely the 3 top candidates - all the files in the db folder which are rather big). For those objects we need to try to avoid frequent persistence and the keep the conversion to protobuf on a separate thread. Then there are objects which are rather small but gets written frequently. For those we should check which ones are critical if there is a state mismatch. Navigation or Peers for instance are totally non-critical but others like SequenceNrMap are likely more problematic.

To let the storage objects decide how the threading is handled would be good.

For the large objects (DaoState, TradeStatistics, AccountAgeWitness) we will need anyway once a solution which is scalable. Maybe its the right time to think about whats the best options are? One idea was to split them into "historical" static data which gets shipped via resources and never gets updated/written and the dynamic part (as it is now). If we can keep the dynamic part small (e.g. the data from the last release) I think we have reduced the protobuf conversion cost by > 90%.

If this all turns out to a larger and difficult project we should also consider if a database solution would be better, but that is probably also a bigger project...

[julianknutsen]

I got a little too deep into the perf work here and wanted to share the summary of information for the person that picks this up.

I think guaranteeing correctness outweighs performance at a high-level. The current code "works" because there isn't a lot of state change once Bisq is up and running and even if there is corruption it is likely overridden quickly enough with the next save. All of this persistence is just a network bandwidth optimization so worst case, refetching everything from the seed nodes is an option.

But, fixing the correctness and keeping it performant is not a small project. The persisted objects have multiple fields and mutable getters/setters which make it extremely difficult to understand the calling contexts for each object and how to efficiently synchronize them. There are plenty of ways this can be done at the design-level, but translating that into actually PRs will require quite a bit of work.

With that said, I have a few small diffs and traces I want to share to help future viewers understand the performance.

Make it correct

This patch just does the toProtoMessage synchronization on the UserThread. It ensures that the iteration bug can't happen because the iteration also happens on the UserThread.

[BUGFIX]_Call_toProtoMessage_on_UserThread.txt

Make it fast (sort of...)

If the toProtoMessage has to be done on the UserThread, the next step is to profile that code and see what is slow. The results show that the DaoStateStore is the worst offender followed by AccountAgeWitnessStore and TradeStatistics2Store as far as totalTime. The preferences payload is also over 100ms.

Why is DaoStateStore slow?
12-9-futuretask-user-thread(RENAMEJPS).txt

Millions of "fast" calls. Having to serialize every transaction and every block is expensive.

Can we cache Block/Tx toProtoMessage?

No. It turns out that the overhead of caching those objects not only increases the memory footprint but generating the hashCode() for the cache/map takes just as long as serialization.

Can we cache serialized DaoState for faster iterative saves?
Potentially, but this requires synchronizing all DaoState modifications and without testing it is high-risk to modify any of that code.

Can we use concurrency?
parallelStream.txt

Yes. Using the parallelStream() construct for the top 3 objects (DaoStateStore, AccountAgeWitnessStore, TradeStatistics2Store) shows some performance gains. Keep in mind this is on a 4 core VM so actual results on low-end hardware won't be nearly as interesting. It also uses the global ForkJoin pool so if this pattern is repeated on multiple threads it also won't be as beneficial. Even with these changes, you are looking at 100ms+ delays on the UserThread which may be a non-starter.

So overall, these are the "best" option that I found in my investigation that doesn't require an extended dev effort. Performance is tricky and there isn't enough testing of the persistable objects where I would feel confident making changes without a lot of manual testing overhead or high-risk bug introduction. See #3773 for my comments on similar perf optimizations in the same layer.

I am also just documenting this here as opposed to PRs because I don't think I am the right person to be responsible for this change and the performance impacts moving forward. I'm happy to help investigate, but someone with much more context of the system should be responsible for the maintenance of it.

[chimp1984]

Thanks @julianknutsen for the work on that!

I think performance optimisation in the DaoState is required anyway (and I saw some work has started there).

For the nr. 2 and 3 of the performance bottleneck candidates (tradestats, account age witness) I think we should look into a solution to split up the historical data and only keep the most recent data as dynamic data structure which would become much smaller (I estimate a few % of the current data size). As those data are "append only" and carry much less complexity than the DAO domain I think that might be a good candidate for improvement.

SequenceNyMap uses a max size, we might consider to lower that so it decreases the object size and with it the CPU costs for persisting. Also tuning of the persistence intervals can help here.

Preferences should not be written to disk often, if so, we should find out why and fix it if its not required. Also here we can increase peristence interval.