Hi there,
today we have bumped into a weird behaviour which I can't grok. We got an old/invalid value for a :1 relationship to an important object (important enough we even added its FK to the modelled locked attributes aside of the PK; not that it helped any, but thanks to that, we see the current snapshot values in the database operations).
1. user A stored new object into the relationship; since we log all database operations, we can see for his EC how this happened:
11:00:12.995 UPDATE on 'DBAuction' ((uid = 1005602) and (lastValidPriceOfferID = 1061694)) -> {lastValidPriceOfferID:1061695}
The saveChanges operation did not fail and the appropriate R/R loop did end without a glitch, no exception, no problem at all, at 11:00:13.036.
2. user B changed the object; again, we can see for his EC
11:00:25.220 UPDATE on 'DBAuction' ((uid = 1005602) and (lastValidPriceOfferID = 1061695)) -> {lastValidPriceOfferID:1061698}
The saveChanges operation again finished successfully and the appropriate R/R loop did end all right at 11:00:25.424.
3. in a new R/R loop which started at 11:00:40.947, user A read the value (the very standard way through storedValueForKey('lastValidPriceOffer') — which is the one we observe all the time, modelled as a simple :1 relationship with FK lastValidPriceOfferID) —, and got the stale object PK:1061695!
How is it possible that the step 2 did not update values in user A's EC? Incidentally, to make extra sure we do not get stale values even if R/R threads happen to overlap, the code uses in the step 3 looks like this:
synchronized (alock) { // lock for the DBAuction 1005602 object (conceptually on PK to lock out all users regardless their ECs)
try {
auction.editingContext().unlock() // so as to process recent changes from other ECs (thanks, Chuck!)
auction.editingContext().lock() // of course we have to keep it locked
DBPriceOffer wins=auction.lastValidPriceOffer() // simply calls storedValueForKey('lastValidPriceOffer')
println "... last valid $wins"
and this very log shows we have got the old price offer, the one with PK:1061695.
I could understand this if user A changed the object to 1061695 and did not save it (in which case the EC sync would not touch the change; but then it would be all right, if the change was not saved), but he very definitely did save the 1061695 successfully in step 1, and never changed it later (until he got it again — the old/invalid value! — in step 3).
Can anyone see a scenario which would lead to him seeing still 1061695 in step 3, regardless that
- he did save it successfully at 11:00:12 and never changed it later;
- another user did change it to 1061698 and successfully did save at 11:00:25;
- aside of the extra lock/unlock shown above, there is no manual EC locking, ECs are auto-locked at R/Rs;
- and besides, even if the extra lock/unlock was not used, the R/R threads here did not overlap, so the change should be synced all right, and the user should get 1061698 in the step 3?
What do I overlook?
Thanks and all the best,
OC