Hi everybody
I’m getting the next exception
Mar 10 16:04:27 Compliance[5000] DEBUG er.transaction.adaptor.Exceptions -
Database Exception occured: java.lang.IllegalStateException: Cannot obtain globalId
for an object which is registered in an other than the databaseContext's active
editingContext, object: <com.qoslabs.tm.wo.eo.EOTopic pk:"26">,
databaseContext: er.extensions.ERXDatabaseContext@1f4e571, object's editingContext:
com.qoslabs.tm.wo.MyEC@ae864e, databaseContext's active editingContext: com.qoslabs.tm.wo.MyEC@148e70d
After it happens, it appears more times and my
application got dead-locks and start increasing the number of worker threads.
I’m working with a Web Service in WO 5.4 using
Wonder 4.0.0.484. I’m using a test client to send many request to the Web
Service, I could work fine using 4 clients (2,000 transaction each client) at
time. But when I increased the number of clients (generally 8, but I test with
5 once) I get the exception randomly (sometimes I could process more than 6,000
transactions and other times only 50-70 transactions). Every request creates
its own transaction and its own peer editing context. Many transactions build
relationships with common EO’s used as types for others.
Looking the trace, I notice that the EC MyEC@148e70d at WorkerThread11 is
saving its changes, it posts a notification to update others EC and it reaches
the other EC MyEC@ae864e. Here a
common EO should to be updated, because its to-many relationship was modified by
first EC (removing an EO in this case, but happens when adds too) but the
common EO was a fault in second EC and it tries to read it getting the
exception because the first EC it’s the active EC in Database Context. The
second EC was created by another thread (WorkerThread15) but notification was process
by same thread (WorkerThread11)
that creates and saves first EC.
I know and I read about this exception in mailing
list, a common mistake is to relate two EO’s in different EC’s. I
check my code and I only use addObjectToBothSidesOfRelationshipWithKey method
to do relationships (even I comment all the methods in my EO’s to set, addTo
or removeFrom relationships), and I extend from Wonder class ERXGenericRecord,
it overrides the method addObjectToBothSidesOfRelationshipWithKey and it verifies
that this.editingContext() == eo.editingContext(). So I don’t think this should
be the reason.
I could say that increasing concurrency I got the
exception, but I don’t know why. And it happens too with WO 5.3.3.
Is there another reason for the exception?
Someone has any idea to follow?
Anyone can help me?
Regards
Federico
The complete stack trace:
WorkerThread15 Start
TestEngine-5[81] - com.qoslabs.tm.wo.TMTransaction@11da969 - com.qoslabs.tm.wo.MyEC@ae864e
<< WorkerThread12 - to saveChanges:
com.qoslabs.tm.wo.TMTransaction@4fd90d - com.qoslabs.tm.wo.MyEC@e3e282
Mar 10 16:04:26 Compliance[5000] INFO com.qoslabs.tm.core.webservice.TMWebService
- The QosTransaction TestEngine-6[87] was OK
Mar 10 16:04:26 Compliance[5000] INFO com.qoslabs.tm.core.webservice.TMWebService
- The QosTransaction TestEngine-3[80] was OK
Mar 10 16:04:26 Compliance[5000] INFO com.qoslabs.tm.core.webservice.TMWebService
- The QosTransaction TestEngine-4[87] was OK
Mar 10 16:04:26 Compliance[5000] INFO com.qoslabs.tm.core.webservice.TMWebService
- The QosTransaction TestEngine-7[80] was OK
WorkerThread13 Start
TestEngine-2[95] - com.qoslabs.tm.wo.TMTransaction@1ea179c - com.qoslabs.tm.wo.MyEC@6bc081
WorkerThread12 Start
TestEngine-4[88] - com.qoslabs.tm.wo.TMTransaction@1febedb - com.qoslabs.tm.wo.MyEC@12f0f6
WorkerThread11 Start
TestEngine-7[81] - com.qoslabs.tm.wo.TMTransaction@b3dfa6 - com.qoslabs.tm.wo.MyEC@148e70d
WorkerThread0 Start
TestEngine-3[81] - com.qoslabs.tm.wo.TMTransaction@1f879fb - com.qoslabs.tm.wo.MyEC@28f4f5
Mar 10 16:04:27 Compliance[5000] INFO com.qoslabs.tm.core.webservice.TMWebService
- The QosTransaction TestEngine-8[86] was OK
<< WorkerThread11 - to saveChanges:
com.qoslabs.tm.wo.TMTransaction@b3dfa6 - com.qoslabs.tm.wo.MyEC@148e70d
Mar 10 16:04:27 Compliance[5000] DEBUG er.transaction.adaptor.Exceptions -
Database Exception occured: java.lang.IllegalStateException: Cannot obtain globalId
for an object which is registered in an other than the databaseContext's active
editingContext, object: <com.qoslabs.tm.wo.eo.EOTopic pk:"26">,
databaseContext: er.extensions.ERXDatabaseContext@1f4e571, object's editingContext:
com.qoslabs.tm.wo.MyEC@ae864e, databaseContext's
active editingContext: com.qoslabs.tm.wo.MyEC@148e70d
java.lang.IllegalStateException:
Cannot obtain globalId for an object which is registered in an other than the databaseContext's
active editingContext, object: <com.qoslabs.tm.wo.eo.EOTopic pk:"26">,
databaseContext: er.extensions.ERXDatabaseContext@1f4e571, object's editingContext:
com.qoslabs.tm.wo.MyEC@ae864e, databaseContext's active editingContext: com.qoslabs.tm.wo.MyEC@148e70d
at
com.webobjects.eoaccess.EODatabaseContext._globalIDForObject(EODatabaseContext.java:4656)
at
com.webobjects.eoaccess.EODatabaseContext.databaseOperationForObject(EODatabaseContext.java:4763)
at
com.webobjects.eoaccess.EODatabaseContext.valuesForKeys(EODatabaseContext.java:6531)
at
com.webobjects.eocontrol.EOObjectStoreCoordinator.valuesForKeys(EOObjectStoreCoordinator.java:326)
at
com.webobjects.eoaccess.EOQualifierSQLGeneration$_KeyValueQualifierSupport.schemaBasedQualifierWithRootEntity(EOQualifierSQLGeneration.java:439)
at
er.extensions.ERXExtensions$KeyValueQualifierSQLGenerationSupport.schemaBasedQualifierWithRootEntity(ERXExtensions.java:277)
at
com.webobjects.eoaccess.EOQualifierSQLGeneration$Support._schemaBasedQualifierWithRootEntity(EOQualifierSQLGeneration.java:179)
at
com.webobjects.eoaccess.EODatabaseChannel.selectObjectsWithFetchSpecification(EODatabaseChannel.java:227)
at
com.webobjects.eoaccess.EODatabaseContext._objectsWithFetchSpecificationEditingContext(EODatabaseContext.java:3055)
at
er.extensions.ERXDatabaseContext._objectsWithFetchSpecificationEditingContext(ERXDatabaseContext.java:57)
at
com.webobjects.eoaccess.EODatabaseContext.objectsWithFetchSpecification(EODatabaseContext.java:3195)
at
com.webobjects.eocontrol.EOObjectStoreCoordinator.objectsWithFetchSpecification(EOObjectStoreCoordinator.java:488)
at
com.webobjects.eocontrol.EOEditingContext.objectsWithFetchSpecification(EOEditingContext.java:4053)
at
er.extensions.ERXEC.objectsWithFetchSpecification(ERXEC.java:1065)
at
com.webobjects.eoaccess.EODatabaseContext.objectsForSourceGlobalID(EODatabaseContext.java:4084)
at
er.extensions.ERXDatabaseContext.objectsForSourceGlobalID(ERXDatabaseContext.java:40)
at
com.webobjects.eocontrol.EOObjectStoreCoordinator.objectsForSourceGlobalID(EOObjectStoreCoordinator.java:634)
at
com.webobjects.eocontrol.EOEditingContext.objectsForSourceGlobalID(EOEditingContext.java:3907)
at
er.extensions.ERXEC.objectsForSourceGlobalID(ERXEC.java:1026)
at
com.webobjects.eoaccess.EODatabaseContext._fireArrayFault(EODatabaseContext.java:4245)
at
com.webobjects.eoaccess.EOAccessArrayFaultHandler.completeInitializationOfObject(EOAccessArrayFaultHandler.java:77)
at
com.webobjects.eocontrol._EOCheapCopyMutableArray.willRead(_EOCheapCopyMutableArray.java:45)
at
com.webobjects.eocontrol._EOCheapCopyMutableArray.count(_EOCheapCopyMutableArray.java:103)
at
com.webobjects.foundation.NSArray.containsObject(NSArray.java:460)
at
com.webobjects.eocontrol.EOCustomObject.excludeObjectFromPropertyWithKey(EOCustomObject.java:967)
at
er.extensions.ERXGenericRecord.excludeObjectFromPropertyWithKey(ERXGenericRecord.java:1197)
at
com.qoslabs.tm.wo.eo.TMGenericRecord.excludeObjectFromPropertyWithKey(TMGenericRecord.java:31)
at
com.qoslabs.tm.wo.eo._EOGEN_EOTopic.removeFromOccurTypes(_EOGEN_EOTopic.java:482)
at
sun.reflect.GeneratedMethodAccessor87.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at
java.lang.reflect.Method.invoke(Method.java:585)
at
com.webobjects.foundation.NSSelector._safeInvokeMethod(NSSelector.java:122)
at
com.webobjects.eocontrol.EOCustomObject.removeObjectFromPropertyWithKey(EOCustomObject.java:1004)
at
com.webobjects.eocontrol.EOClassDescription.propagateDeleteForObject(EOClassDescription.java:464)
at
com.webobjects.eocontrol.EOCustomObject.propagateDeleteWithEditingContext(EOCustomObject.java:693)
at
com.webobjects.eocontrol.EOEditingContext.propagateDeletesUsingTable(EOEditingContext.java:2245)
at
com.webobjects.eocontrol.EOEditingContext._processDeletedObjects(EOEditingContext.java:2207)
at
com.webobjects.eocontrol.EOEditingContext._processRecentChanges(EOEditingContext.java:1767)
at
com.webobjects.eocontrol.EOEditingContext.processRecentChanges(EOEditingContext.java:1966)
at
er.extensions.ERXEC.processRecentChanges(ERXEC.java:616)
at
com.webobjects.eocontrol.EOEditingContext._processObjectStoreChanges(EOEditingContext.java:3484)
at
sun.reflect.GeneratedMethodAccessor63.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at
java.lang.reflect.Method.invoke(Method.java:585)
at
com.webobjects.foundation.NSSelector.invoke(NSSelector.java:358)
at
com.webobjects.foundation.NSSelector._safeInvokeSelector(NSSelector.java:110)
at
com.webobjects.eocontrol.EOEditingContext._processNotificationQueue(EOEditingContext.java:4725)
at
com.webobjects.eocontrol.EOEditingContext.lock(EOEditingContext.java:4604)
at
er.extensions.ERXEC.lock(ERXEC.java:437)
at
com.qoslabs.tm.wo.MyEC.lock(TMTransaction.java:224)
at
com.webobjects.eocontrol.EOEditingContext.tryLock(EOEditingContext.java:4616)
at
com.webobjects.eocontrol.EOEditingContext._sendOrEnqueueNotification(EOEditingContext.java:4689)
at
com.webobjects.eocontrol.EOEditingContext._globalIDChanged(EOEditingContext.java:2035)
at
sun.reflect.GeneratedMethodAccessor56.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at
java.lang.reflect.Method.invoke(Method.java:585)
at
com.webobjects.foundation.NSSelector._safeInvokeMethod(NSSelector.java:122)
at
com.webobjects.foundation.NSNotificationCenter$_Entry.invokeMethod(NSNotificationCenter.java:588)
at
com.webobjects.foundation.NSNotificationCenter.postNotification(NSNotificationCenter.java:532)
at
com.webobjects.foundation.NSNotificationCenter.postNotification(NSNotificationCenter.java:562)
at
com.webobjects.eocontrol.EOObjectStoreCoordinator._globalIDsChangedInSubStore(EOObjectStoreCoordinator.java:698)
at
sun.reflect.GeneratedMethodAccessor55.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at
java.lang.reflect.Method.invoke(Method.java:585)
at
com.webobjects.foundation.NSSelector._safeInvokeMethod(NSSelector.java:122)
at
com.webobjects.foundation.NSNotificationCenter$_Entry.invokeMethod(NSNotificationCenter.java:588)
at
com.webobjects.foundation.NSNotificationCenter.postNotification(NSNotificationCenter.java:532)
at
com.webobjects.foundation.NSNotificationCenter.postNotification(NSNotificationCenter.java:562)
at
com.webobjects.eoaccess.EODatabaseContext.commitChanges(EODatabaseContext.java:6373)
at
com.webobjects.eocontrol.EOObjectStoreCoordinator.saveChangesInEditingContext(EOObjectStoreCoordinator.java:386)
at
com.webobjects.eocontrol.EOEditingContext.saveChanges(EOEditingContext.java:3176)
at
er.extensions.ERXEC._saveChanges(ERXEC.java:937)
at
er.extensions.ERXEC.saveChanges(ERXEC.java:860)
at
com.qoslabs.tm.wo.TMTransaction.commit(TMTransaction.java:82)
at
com.qoslabs.tm.core.webservice.TMWebService.setTopicMap(TMWebService.java:299)
at
sun.reflect.GeneratedMethodAccessor79.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at
java.lang.reflect.Method.invoke(Method.java:585)
at
org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java:397)
at
org.apache.axis.providers.java.RPCProvider.processMessage(RPCProvider.java:186)
at
org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:323)
at
org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32)
at
org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118)
at
org.apache.axis.SimpleChain.invoke(SimpleChain.java:83)
at
org.apache.axis.handlers.soap.SOAPService.invoke(SOAPService.java:454)
at
org.apache.axis.server.AxisServer.invoke(AxisServer.java:281)
at
com.webobjects.appserver._private.WOWebService.performActionNamed(WOWebService.java:436)
at
com.webobjects.appserver._private.WOActionRequestHandler._handleRequest(WOActionRequestHandler.java:259)
at
com.webobjects.appserver._private.WOActionRequestHandler.handleRequest(WOActionRequestHandler.java:161)
at
com.webobjects.appserver._private.WOWebServiceRequestHandler.handleRequest(WOWebServiceRequestHandler.java:109)
at
com.webobjects.appserver.WOApplication.dispatchRequest(WOApplication.java:1678)
at
er.extensions.ERXApplication.dispatchRequest(ERXApplication.java:1439)
at
com.webobjects.appserver._private.WOWorkerThread.runOnce(WOWorkerThread.java:144)
at
com.webobjects.appserver._private.WOWorkerThread.run(WOWorkerThread.java:226)
at
java.lang.Thread.run(Thread.java:595)
*** FHG: WorkerThread11
for Key: occurTypes - <com.qoslabs.tm.wo.eo.EOTopic pk:"26"> isFault:
false - com.qoslabs.tm.wo.MyEC@ae864e - <com.qoslabs.tm.wo.eo.EOOccurrence
pk:"1431">
MyEC catch error: com.qoslabs.tm.wo.MyEC@ae864e
--- rootObjectStore: com.webobjects.eocontrol.EOObjectStoreCoordinator@17cec96
- true
WorkerThread11 - com.qoslabs.tm.wo.MyEC@ae864e
registered: 119
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOLocator pk:"null"> EC: com.qoslabs.tm.wo.MyEC@ae864e
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOOccurrence pk:"null"> EC: com.qoslabs.tm.wo.MyEC@ae864e
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOLocator pk:"null"> EC: com.qoslabs.tm.wo.MyEC@ae864e
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOLocator pk:"null"> EC: com.qoslabs.tm.wo.MyEC@ae864e
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOOccurrence pk:"null"> EC: com.qoslabs.tm.wo.MyEC@ae864e
<< WorkerThread11 inserted:
<com.qoslabs.tm.wo.eo.EOLocator pk:"null"> EC: com.qoslabs.tm.wo.MyEC@ae864e
<< WorkerThread11
updated: <com.qoslabs.tm.wo.eo.EOTopic pk:"1432"> EC: com.qoslabs.tm.wo.MyEC@ae864e
<< WorkerThread11
updated: <com.qoslabs.tm.wo.eo.EOOccurrence pk:"158"> EC: com.qoslabs.tm.wo.MyEC@ae864e
<< WorkerThread11
updated: <com.qoslabs.tm.wo.eo.EOTopic pk:"17"> EC: com.qoslabs.tm.wo.MyEC@ae864e
<< WorkerThread11
deleted: <com.qoslabs.tm.wo.eo.EOOccurrence pk:"1431"> EC: com.qoslabs.tm.wo.MyEC@ae864e
<< WorkerThread11
deleted: <com.qoslabs.tm.wo.eo.EOLocator pk:"1345"> EC: com.qoslabs.tm.wo.MyEC@ae864e
****** OPS troubles in: com.qoslabs.tm.wo.TMTransaction@b3dfa6
- com.qoslabs.tm.wo.MyEC@148e70d - WorkerThread11
--- rootObjectStore: com.webobjects.eocontrol.EOObjectStoreCoordinator@17cec96
- true
WorkerThread11 - com.qoslabs.tm.wo.MyEC@148e70d
registered: 118
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOOccurrence pk:"1497"> EC: com.qoslabs.tm.wo.MyEC@148e70d
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOLocator pk:"1402"> EC: com.qoslabs.tm.wo.MyEC@148e70d
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOOccurrence pk:"1498"> EC: com.qoslabs.tm.wo.MyEC@148e70d
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOLocator pk:"1403"> EC: com.qoslabs.tm.wo.MyEC@148e70d
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOLocator pk:"1404"> EC: com.qoslabs.tm.wo.MyEC@148e70d
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOLocator pk:"1405"> EC: com.qoslabs.tm.wo.MyEC@148e70d
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOBaseName pk:"1499"> EC: com.qoslabs.tm.wo.MyEC@148e70d
<< WorkerThread11
inserted: <com.qoslabs.tm.wo.eo.EOTopic pk:"1500"> EC: com.qoslabs.tm.wo.MyEC@148e70d
<< WorkerThread11
updated: <com.qoslabs.tm.wo.eo.EOTopic pk:"13"> EC: com.qoslabs.tm.wo.MyEC@148e70d
<< WorkerThread11
updated: <com.qoslabs.tm.wo.eo.EOTopic pk:"17"> EC: com.qoslabs.tm.wo.MyEC@148e70d
<< WorkerThread11 updated:
<com.qoslabs.tm.wo.eo.EOOccurrence pk:"195"> EC: com.qoslabs.tm.wo.MyEC@148e70d