Mailing List webobjects-dev@wocommunity.org Message #102
From: Jeffrey Schmitz <webobjects-dev@wocommunity.org>
Subject: Re: [WO-DEV] ERXObjectStoreCoordinatorSynchronizer woes
Date: Sun, 21 Mar 2021 10:27:28 -0500
To: WebObjects & WOnder Development <webobjects-dev@wocommunity.org>
On a perhaps related note, under the same conditions as you describe running in a background task, e.g...

 EOEditingContext updateEC = ERXEC.newTolerantEditingContext(objStore);
 Pool updatePool;
try {
<DO STUFF>
 try {
   updateEC.lock();
     <DO DATABASE UPDATES>
   updateEC.saveChanges();

  } finally {
   updateEC.unlock();
   updateEC.dispose();
  }
} catch (Exception ex) {
   Logger.info("EXCEPTION WHILE PROCESSING CALC CAN I WIN for pool type " + this.poolType + poolName);
   ex.printStackTrace(System.out);


 I had a case where the ERXEC._saveChanges got into an infinite recursion loop after getting an update exception.  I've pasted the stack trace below in the early parts of the recursion, but the exceptions continued with another call to:

 at er.extensions.eof.ERXEC._saveChanges(ERXEC.java:1190)  

added to each stack trace until I killed the application instance.

Mar 19 12:08:46 netbrackets[2001] WARN  er.extensions.eof.ERXEC  - _saveChangesTolerantly: Exception occurred
EOGeneralAdaptorException: updateValuesInRowDescribedByQualifier -- er.extensions.jdbc.ERXJDBCAdaptor$Channel method failed to update row in database
  at com.webobjects.eoaccess.EODatabaseContext._exceptionWithDatabaseContextInformationAdded(EODatabaseContext.java:4504)
     ... skipped 1 stack elements
  at com.webobjects.eocontrol.EOObjectStoreCoordinator.saveChangesInEditingContext(EOObjectStoreCoordinator.java:376)
  at com.webobjects.eocontrol.EOEditingContext.saveChanges(EOEditingContext.java:3192)
  at er.extensions.eof.ERXEC._saveChanges(ERXEC.java:1178)
  at er.extensions.eof.ERXEC._saveChanges(ERXEC.java:1190)
  at er.extensions.eof.ERXEC._saveChanges(ERXEC.java:1190)
  at er.extensions.eof.ERXEC._saveChanges(ERXEC.java:1190)
  at er.extensions.eof.ERXEC.saveChanges(ERXEC.java:1099)
  at com.netbracketsfw.core.CalcUtils.calcCanIWinsWithGiS(CalcUtils.java:4611)

I've never seen this behavior before.  Note the exception never bubbled up to my surrounding exception handler shown in the code.

Any ideas?
Jeff


On Mar 20, 2021, at 11:01 PM, OCsite <webobjects-dev@wocommunity.org> wrote:

Hi there,

occasionally (not too often), we are running a background import task, which uses its own EO stack: at launch, it creates a new EOObjectStoreCoordinator (and for it it creates an ERXEC and uses it to import data). When done and saved, the coordinator is disposed and released. The rationale is that the imported data might be big and we don't want to limit normal workers processing to wait until the import saves its results into the database.

For a long long time it worked reliably and without a glitch.

Lately, it often (though by far not each time!) happens that

(i) a save in the background task reports the following exception:

===
04:38:38.600 ERROR java.lang.NullPointerException       //log:er.extensions.eof.ERXObjectStoreCoordinatorSynchronizer [ERXOSCProcessChanges]
NullPointerException
  at com.webobjects.eoaccess.EOModelGroup.modelGroupForObjectStoreCoordinator(EOModelGroup.java:795)
  at er.extensions.eof.ERXEOAccessUtilities.databaseContextForEntityNamed(ERXEOAccessUtilities.java:1086)
  at er.extensions.eof.ERXObjectStoreCoordinatorSynchronizer$ProcessChangesQueue._process(ERXObjectStoreCoordinatorSynchronizer.java:509)
  at er.extensions.eof.ERXObjectStoreCoordinatorSynchronizer$ProcessChangesQueue.process(ERXObjectStoreCoordinatorSynchronizer.java:540)
  at er.extensions.eof.ERXObjectStoreCoordinatorSynchronizer$ProcessChangesQueue.run(ERXObjectStoreCoordinatorSynchronizer.java:617)
  ... skipped 1 stack elements
===

(ii) after that, usually no more exceptions are reported, but the ERXObjectStoreCoordinatorSynchronizer does not seem to work properly anymore, and it often happens that the changes done in the background task are not visible in the main OSC for awhile.

From the user's perspective it usually means that the import is finished, but the imported data is not visible for a long long time (does not seem to be just a fetchTimestampLag, for newly logged-in users with their new sessions and new ECs still don't see the imported data for awhile. Frankly, I can't see what the H. might be the culprit :/ )

(iii) another problem which seems to be also caused (perhaps indirectly) by the above exception is that the application cannot be normally quit from JavaMonitor, reporting upon an attempt

===
04:33:43.441 ERROR Exception caught: null
... ...
IllegalStateException: Attempted to stop the ProcessChangesQueue when it wasn't already running
  at er.extensions.eof.ERXObjectStoreCoordinatorSynchronizer$ProcessChangesQueue.stop(ERXObjectStoreCoordinatorSynchronizer.java:637)
  at er.extensions.eof.ERXObjectStoreCoordinatorSynchronizer.stopRemoteSynchronizer(ERXObjectStoreCoordinatorSynchronizer.java:132)
     ... skipped 8 stack elements
  at er.extensions.appserver.ERXApplication.terminate(ERXApplication.java:2861)
... ...
===

Any idea what might be the culprit and how to fix it?

Thanks and all the best,
OC


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