Re: [WO-DEV] old/invalid :1 relationship value, how the H. possible?!?
Re: [WO-DEV] old/invalid :1 relationship value, how the H. possible?!?
- Subject: Re: [WO-DEV] old/invalid :1 relationship value, how the H. possible?!?
- From: OCsite via Webobjects-dev <email@hidden>
- Date: Wed, 16 Jun 2021 15:01:48 +0200
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 <email@hidden> 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 <email@hidden
>> <mailto:email@hidden>> 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
>> https://logicsquad.net <https://logicsquad.net/>
>> https://www.linkedin.com/company/logic-squad/
>> <https://www.linkedin.com/company/logic-squad/>
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Webobjects-dev mailing list (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden