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-...@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-...@wocommunity.org >> <mailto:webobjects-...@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 >> 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 (Webobjects-dev@lists.apple.com) Help/Unsubscribe/Update your Subscription: https://lists.apple.com/mailman/options/webobjects-dev/archive%40mail-archive.com This email sent to arch...@mail-archive.com
