race condition while inserting to storage

[patc888]

In the following scenario:

1. Host receives M1 (616129) and M2 (616130)
2. The worker handling M2 is faster than the worker handling M1 and M2 is inserted.
3. However, the M2 worker has not yet acquired the lock to update variables. Therefore 'saving' contains M2.
4. The worker handling M1 discovers that the log already has M1 from an older term and deletes M1 and M2 from storage.
5. M1 is inserted.

The system now incorrectly assumes that M2 is available and the "should be saved but is not" error is displayed.

Here's the logs that show the deletion occurs right after the insertion:

2015-12-03 17:09:33,893 INFO [host3-83] recv(82): AE(cterm=1470 pterm=1467 eterm=1470 index=616129 ci=616127 size=0)
2015-12-03 17:09:33,893 INFO [host3-83] hasEntry(term=1467 index=616128) -> true
2015-12-03 17:09:33,894 INFO [host3-83] recv(82): AE(cterm=1470 pterm=1470 eterm=1470 index=616130 ci=616127 size=8)
2015-12-03 17:09:33,894 INFO [host3-83] SaveQueue: increasing maxGap from 0 to 10
2015-12-03 17:09:33,895 INFO [host3-83] SaveQueue: overwriting index=616129 which is older than the savedIndex=616129. Contents are different.
2015-12-03 17:09:33,895 INFO [host3-83] SaveQueue: Setting savedIndex=616128 and deleting subsequent entries
2015-12-03 17:09:33,895 INFO [host3-83] insert(term=1470 index=616130 size=8) waiters=3 saved=0 contents=B2-41497
2015-12-03 17:09:33,901 INFO [host3-83] SaveQueue: deleting index=616130
2015-12-03 17:09:33,902 INFO [host3-83] SaveQueue: deleting index=616129
2015-12-03 17:09:33,903 INFO [host3-83] send(82): ae(cterm=1470 matchIndex=616128 ok)
2015-12-03 17:09:33,904 INFO [host3-83] select(index=616128) -> term=1467 size=8
2015-12-03 17:09:33,904 INFO [host3-83] insert(term=1470 index=616129 size=0) waiters=4 saved=1 contents=
2015-12-03 17:09:33,904 INFO [host3-83] SaveQueue: pulled index=616130 to 616130 from saved. Remaining=0
2015-12-03 17:09:33,908 INFO [host3-83] select(index=616129) -> term=1470 size=0
2015-12-03 17:09:33,908 INFO [host3-83] select(index=616129) -> term=1470 size=0
2015-12-03 17:09:33,912 ERROR index=616130 should be saved but is not. si=616130 ci=616130
java.lang.IllegalStateException: index=616130 should be saved but is not. si=616130 ci=616130
at com.yahoo.gondola.core.CommitQueue.get(CommitQueue.java:138)
at com.yahoo.gondola.core.CoreMember.getCommittedLogEntry(CoreMember.java:388)
at com.yahoo.gondola.Shard.getCommittedCommand(Shard.java:227)
at com.yahoo.gondola.cli.GondolaCommand$RemoteInterface.processCommand(GondolaCommand.java:433)
at com.yahoo.gondola.cli.GondolaCommand$RemoteInterface.run(GondolaCommand.java:365)
2015-12-03 17:09:34,092 INFO [host3-83] recv(82): AE(cterm=1470 pterm=1470 eterm=1470 index=616131 ci=616130 size=8)
2015-12-03 17:09:34,109 INFO [host3-83] insert(term=1470 index=616131 size=8) waiters=4 saved=0 contents=B2-41498