Mailing List webobjects-dev@wocommunity.org Message #212
From: OCsite <webobjects-dev@wocommunity.org>
Subject: Work-around (was: [WO-DEV] old/invalid :1 relationship value, how the H. possible?!?)
Date: Thu, 17 Jun 2021 21:37:10 +0200
To: WebObjects & WOnder Development <webobjects-dev@wocommunity.org>
Given it did happen — for whichever weird and arcane reason — at least once that after being unlocked/locked an EC still did not have changes saved previously (before the unlock/lock), I am considering to add this work-around for the one very important attribute (well, :1 relationship, but that's essentially same thing):

- whenever its value is being read from an eo, I also get its value from the snapshot[1] and compare them
- if they match, I simply use the value, it's definitely all right
- if they do not match, I'll check whether the eo is in the updatedObjects of its EC. If so, I'll again use the current value, it's probably all right[2]
- if they do not match and the eo is not an updated one, I simply refault it.

This should
- cost essentially nothing in the most common case (access to snapshot is very fast)
- fix the problem — should it happen again — with a very high probability[2]
- cost little even in the worst case (refault + re-read from snapshot is still pretty fast)

Do I overlook something of importance?

[1] Still not sure which one and how all those beasts differ, but I guess EODatabaseContext.snapshotForGlobalID should be most reliable. Hopefully.

[2] There's some danger another attribute/relationship has been changed, and then the one very important was not properly merged. I can't see a reliable solution for this; do you perhaps?

Your thoughts?

Thanks a lot,
OC

On 16. 6. 2021, at 15:01, OCsite <webobjects-dev@wocommunity.org> wrote:

Some followup: I have analysed the R/R loops in details and found that

- the user B saved changes at 11:00:25.220
- at this moment, there was a user A's R/R loop (which never touched the relevant data), running from 11:00:24.570 to 11:00:25.548
- the next user A's R/R loop started at 11:00:38.113, read the relevant data, did not see the changes of 11:00:25.220

In other words,
- at 11:00:25.220, user A's EC was locked; it should not merge the changes immediately...
- ... but, at 11:00:25.548 the user A's EC was unlocked: at this moment the 11:00:25.220 changes should be merged into the EC...
- ... which self-evidently did not happen, for in the next R/R loop started at 11:00:38.113 the 11:00:25.220 changes were still not visible.

How could that happen? What could prevent the merge at the EC unlock/RR loop end?

Thanks for any advice,
OC

On 16 Jun 2021, at 6:35, OCsite <webobjects-dev@wocommunity.org> wrote:

Matthew,

no luck this way: one instance only, and one OSC (ERXObjectStoreCoordinatorPool.maxCoordinators=1).

Thanks,
OC

On 16. 6. 2021, at 2:57, Matthew Ness <webobjects-dev@wocommunity.org> wrote:


On Wed, Jun 16, 2021, at 1:42 AM, OCsite wrote:
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


Hi,

How many instances of the application aretypically running?

Regards,

-- 
Matt


Subscribe (FEED) Subscribe (DIGEST) Subscribe (INDEX) Unsubscribe Mail to Listmaster