• Open Menu Close Menu
  • Apple
  • Shopping Bag
  • Apple
  • Mac
  • iPad
  • iPhone
  • Watch
  • TV
  • Music
  • Support
  • Search apple.com
  • Shopping Bag

Lists

Open Menu Close Menu
  • Terms and Conditions
  • Lists hosted on this site
  • Email the Postmaster
  • Tips for posting to public mailing lists
Re: WebObjects application instances hanging - Deadlocks occurring
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: WebObjects application instances hanging - Deadlocks occurring

  • Subject: Re: WebObjects application instances hanging - Deadlocks occurring
  • From: Chuck Hill <email@hidden>
  • Date: Mon, 24 Nov 2014 16:39:19 +0000
  • Thread-topic: WebObjects application instances hanging - Deadlocks occurring
        at GenericRecord.primaryKeyInt(GenericRecord.java:327)
        at Application.dispatchRequest(Application.java:661)

The Wonder auto-locking won’t have happened in at that point in dispatchRequest.  You need to lock  and unlock it yourself.

Chuck


On 2014-11-24, 8:19 AM, "Raghavender Reddy" wrote:

Hello Ralf,

We have enabled the property "er.extensions.ERXEC.markOpenLocks" in our application, and the following is the attached deadlock exception trace printed in the application log file:

These are the two places in our application code where the deadlock trace is pointed:

1. In the Session java file (extended the ERXSession) following is method code where the trace log is pointed: at Session.setLoginUser(Session.java:110)

 /** Set the login user for the session. */
    public void setLoginUser(SOLARUser value) {
        if ( value != null )
            loginUser = (SOLARUser)EOUtilities.localInstanceOfObject(defaultEditingContext(), value); //line number 110
    }

2. And in the GenericRecord java file (this class has extended the EOGenericRecord and not the ERXGenericRecord), following is method code where the trace log is pointed:  at GenericRecord.primaryKeyDictionary(GenericRecord.java:297)

                    public NSDictionary primaryKeyDictionary()
                    {
                        return EOUtilities.primaryKeyForObject(editingContext(), this); //line number 297
                    }
----------------------------------------------------------------
---------------------------------------------------------------
12749690 [WorkerThread21] DEBUG NSLog  - <com.webobjects.appserver._private.WOClassicAdaptor>: Growing number of WOWorkerThreads to 64
12770675 [WorkerThread25] WARN er.extensions.eof.ERXEC  - 23398687 Attempting to lock editing context from WorkerThread25 that was previously locked in WorkerThread24
 Current stack trace: java.lang.Exception: Locked
        at er.extensions.eof.ERXEC.lock(ERXEC.java:448)
        at er.extensions.eof.ERXEC.autoLock(ERXEC.java:553)
        at er.extensions.eof.ERXEC.globalIDForObject(ERXEC.java:734)
        at com.webobjects.eoaccess.EOUtilities.primaryKeyForObject(EOUtilities.java:880)
        at GenericRecord.primaryKeyDictionary(GenericRecord.java:297)
        at GenericRecord.primaryKeyObject(GenericRecord.java:315)
        at GenericRecord.primaryKeyInt(GenericRecord.java:327)
        at Application.dispatchRequest(Application.java:661)
        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:619)

 Lock count: 1
 Existing lock: java.lang.Exception: Locked
        at er.extensions.eof.ERXEC.lock(ERXEC.java:448)
        at er.extensions.eof.ERXEC.autoLock(ERXEC.java:553)
        at er.extensions.eof.ERXEC.globalIDForObject(ERXEC.java:734)
        at com.webobjects.eoaccess.EOUtilities.primaryKeyForObject(EOUtilities.java:880)
        at GenericRecord.primaryKeyDictionary(GenericRecord.java:297)
        at GenericRecord.primaryKeyObject(GenericRecord.java:315)
        at GenericRecord.primaryKeyInt(GenericRecord.java:327)
        at Application.dispatchRequest(Application.java:661)
        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:619)
 Created: java.lang.Exception: Creation
        at er.extensions.eof.ERXEC.<init>(ERXEC.java:353)
        at er.extensions.eof.ERXEC$DefaultFactory._createEditingContext(ERXEC.java:1492)
        at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1455)
        at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1434)
        at er.extensions.eof.ERXEC.newEditingContext(ERXEC.java:1540)
        at er.extensions.appserver.ERXSession.defaultEditingContext(ERXSession.java:353)
        at Session.setLoginUser(Session.java:110)
        at Main.login(Main.java:185)
        at Main.login(Main.java:120)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
        at com.webobjects.foundation.NSKeyValueCoding$_MethodBinding.valueInObject(NSKeyValueCoding.java:1134)
        at com.webobjects.foundation.NSKeyValueCoding$DefaultImplementation.valueForKey(NSKeyValueCoding.java:1324)
        at com.webobjects.appserver.WOComponent.valueForKey(WOComponent.java:1736)
        at com.webobjects.foundation.NSKeyValueCoding$Utility.valueForKey(NSKeyValueCoding.java:447)
        at com.webobjects.foundation.NSKeyValueCodingAdditions$DefaultImplementation.valueForKeyPath(NSKeyValueCodingAdditions.java:212)
        at com.webobjects.appserver.WOComponent.valueForKeyPath(WOComponent.java:1804)
        at com.webobjects.appserver._private.WOKeyValueAssociation.valueInComponent(WOKeyValueAssociation.java:50)
        at com.webobjects.appserver._private.WOSubmitButton.invokeAction(WOSubmitButton.java:70)
        at er.extensions.foundation.ERXPatcher$DynamicElementsPatches$SubmitButton.invokeAction(ERXPatcher.java:214)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at er.extensions.components._private.ERXWOForm.invokeAction(ERXWOForm.java:180)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOComponentContent.invokeAction(WOComponentContent.java:38)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOConditional.invokeAction(WOConditional.java:86)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOHTMLURLValuedElement.invokeAction(WOHTMLURLValuedElement.java:149)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
        at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:92)
        at com.webobjects.appserver._private.WOComponentReference.invokeAction(WOComponentReference.java:127)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOConditional.invokeAction(WOConditional.java:86)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
        at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:92)
        at com.webobjects.appserver.WOSession.invokeAction(WOSession.java:1357)
        at Session.invokeAction(Session.java:195)
        at com.webobjects.appserver.WOApplication.invokeAction(WOApplication.java:1745)
        at er.extensions.appserver.ajax.ERXAjaxApplication.invokeAction(ERXAjaxApplication.java:50)
        at er.extensions.appserver.ERXApplication.invokeAction(ERXApplication.java:1687)
        at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedPage(WOComponentRequestHandler.java:206)
        at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedSession(WOComponentRequestHandler.java:298)
        at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedApplication(WOComponentRequestHandler.java:332)
        at com.webobjects.appserver._private.WOComponentRequestHandler._handleRequest(WOComponentRequestHandler.java:369)
        at com.webobjects.appserver._private.WOComponentRequestHandler.handleRequest(WOComponentRequestHandler.java:442)
        at com.webobjects.appserver.WOApplication.dispatchRequest(WOApplication.java:1687)
        at er.extensions.appserver.ERXApplication.dispatchRequestImmediately(ERXApplication.java:1802)
        at er.extensions.appserver.ERXApplication.dispatchRequest(ERXApplication.java:1767)
        at Application.dispatchRequest(Application.java:653)
        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:619)

12770679 [WorkerThread27] WARN er.extensions.eof.ERXEC  - 23398687 Attempting to lock editing context from WorkerThread27 that was previously locked in WorkerThread24
 Current stack trace: java.lang.Exception: Locked
        at er.extensions.eof.ERXEC.lock(ERXEC.java:448)
        at er.extensions.eof.ERXEC.autoLock(ERXEC.java:553)
        at er.extensions.eof.ERXEC.globalIDForObject(ERXEC.java:734)
        at com.webobjects.eoaccess.EOUtilities.primaryKeyForObject(EOUtilities.java:880)
        at GenericRecord.primaryKeyDictionary(GenericRecord.java:297)
        at GenericRecord.primaryKeyObject(GenericRecord.java:315)
        at GenericRecord.primaryKeyInt(GenericRecord.java:327)
        at Application.dispatchRequest(Application.java:661)
        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:619)

 Lock count: 1
 Existing lock: java.lang.Exception: Locked
        at er.extensions.eof.ERXEC.lock(ERXEC.java:448)
        at er.extensions.eof.ERXEC.autoLock(ERXEC.java:553)
        at er.extensions.eof.ERXEC.globalIDForObject(ERXEC.java:734)
        at com.webobjects.eoaccess.EOUtilities.primaryKeyForObject(EOUtilities.java:880)
        at GenericRecord.primaryKeyDictionary(GenericRecord.java:297)
        at GenericRecord.primaryKeyObject(GenericRecord.java:315)
        at GenericRecord.primaryKeyInt(GenericRecord.java:327)
        at Application.dispatchRequest(Application.java:661)
        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:619)
 Created: java.lang.Exception: Creation
        at er.extensions.eof.ERXEC.<init>(ERXEC.java:353)
        at er.extensions.eof.ERXEC$DefaultFactory._createEditingContext(ERXEC.java:1492)
        at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1455)
        at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1434)
        at er.extensions.eof.ERXEC.newEditingContext(ERXEC.java:1540)
        at er.extensions.appserver.ERXSession.defaultEditingContext(ERXSession.java:353)
        at Session.setLoginUser(Session.java:110)
        at Main.login(Main.java:185)
        at Main.login(Main.java:120)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
        at com.webobjects.foundation.NSKeyValueCoding$_MethodBinding.valueInObject(NSKeyValueCoding.java:1134)
        at com.webobjects.foundation.NSKeyValueCoding$DefaultImplementation.valueForKey(NSKeyValueCoding.java:1324)
        at com.webobjects.appserver.WOComponent.valueForKey(WOComponent.java:1736)
        at com.webobjects.foundation.NSKeyValueCoding$Utility.valueForKey(NSKeyValueCoding.java:447)
        at com.webobjects.foundation.NSKeyValueCodingAdditions$DefaultImplementation.valueForKeyPath(NSKeyValueCodingAdditions.java:212)
        at com.webobjects.appserver.WOComponent.valueForKeyPath(WOComponent.java:1804)
        at com.webobjects.appserver._private.WOKeyValueAssociation.valueInComponent(WOKeyValueAssociation.java:50)
        at com.webobjects.appserver._private.WOSubmitButton.invokeAction(WOSubmitButton.java:70)
        at er.extensions.foundation.ERXPatcher$DynamicElementsPatches$SubmitButton.invokeAction(ERXPatcher.java:214)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at er.extensions.components._private.ERXWOForm.invokeAction(ERXWOForm.java:180)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOComponentContent.invokeAction(WOComponentContent.java:38)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOConditional.invokeAction(WOConditional.java:86)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOHTMLURLValuedElement.invokeAction(WOHTMLURLValuedElement.java:149)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
        at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:92)
        at com.webobjects.appserver._private.WOComponentReference.invokeAction(WOComponentReference.java:127)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOConditional.invokeAction(WOConditional.java:86)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
        at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:92)
        at com.webobjects.appserver.WOSession.invokeAction(WOSession.java:1357)
        at Session.invokeAction(Session.java:195)
        at com.webobjects.appserver.WOApplication.invokeAction(WOApplication.java:1745)
        at er.extensions.appserver.ajax.ERXAjaxApplication.invokeAction(ERXAjaxApplication.java:50)
        at er.extensions.appserver.ERXApplication.invokeAction(ERXApplication.java:1687)
        at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedPage(WOComponentRequestHandler.java:206)
        at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedSession(WOComponentRequestHandler.java:298)
        at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedApplication(WOComponentRequestHandler.java:332)
        at com.webobjects.appserver._private.WOComponentRequestHandler._handleRequest(WOComponentRequestHandler.java:369)
        at com.webobjects.appserver._private.WOComponentRequestHandler.handleRequest(WOComponentRequestHandler.java:442)
        at com.webobjects.appserver.WOApplication.dispatchRequest(WOApplication.java:1687)
        at er.extensions.appserver.ERXApplication.dispatchRequestImmediately(ERXApplication.java:1802)
        at er.extensions.appserver.ERXApplication.dispatchRequest(ERXApplication.java:1767)
        at Application.dispatchRequest(Application.java:653)
        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:619)

12770683 [WorkerThread26] WARN er.extensions.eof.ERXEC  - 23398687 Attempting to lock editing context from WorkerThread26 that was previously locked in WorkerThread24
 Current stack trace: java.lang.Exception: Locked
        at er.extensions.eof.ERXEC.lock(ERXEC.java:448)
        at er.extensions.eof.ERXEC.autoLock(ERXEC.java:553)
        at er.extensions.eof.ERXEC.globalIDForObject(ERXEC.java:734)
        at com.webobjects.eoaccess.EOUtilities.primaryKeyForObject(EOUtilities.java:880)
        at GenericRecord.primaryKeyDictionary(GenericRecord.java:297)
        at GenericRecord.primaryKeyObject(GenericRecord.java:315)
        at GenericRecord.primaryKeyInt(GenericRecord.java:327)
        at Application.dispatchRequest(Application.java:661)
        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:619)

 Lock count: 1
 Existing lock: java.lang.Exception: Locked
        at er.extensions.eof.ERXEC.lock(ERXEC.java:448)
        at er.extensions.eof.ERXEC.autoLock(ERXEC.java:553)
        at er.extensions.eof.ERXEC.globalIDForObject(ERXEC.java:734)
        at com.webobjects.eoaccess.EOUtilities.primaryKeyForObject(EOUtilities.java:880)
        at GenericRecord.primaryKeyDictionary(GenericRecord.java:297)
        at GenericRecord.primaryKeyObject(GenericRecord.java:315)
        at GenericRecord.primaryKeyInt(GenericRecord.java:327)
        at Application.dispatchRequest(Application.java:661)
        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:619)
 Created: java.lang.Exception: Creation
        at er.extensions.eof.ERXEC.<init>(ERXEC.java:353)
        at er.extensions.eof.ERXEC$DefaultFactory._createEditingContext(ERXEC.java:1492)
        at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1455)
        at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1434)
        at er.extensions.eof.ERXEC.newEditingContext(ERXEC.java:1540)
        at er.extensions.appserver.ERXSession.defaultEditingContext(ERXSession.java:353)
        at Session.setLoginUser(Session.java:110)
        at Main.login(Main.java:185)
        at Main.login(Main.java:120)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
        at com.webobjects.foundation.NSKeyValueCoding$_MethodBinding.valueInObject(NSKeyValueCoding.java:1134)
        at com.webobjects.foundation.NSKeyValueCoding$DefaultImplementation.valueForKey(NSKeyValueCoding.java:1324)
        at com.webobjects.appserver.WOComponent.valueForKey(WOComponent.java:1736)
        at com.webobjects.foundation.NSKeyValueCoding$Utility.valueForKey(NSKeyValueCoding.java:447)
        at com.webobjects.foundation.NSKeyValueCodingAdditions$DefaultImplementation.valueForKeyPath(NSKeyValueCodingAdditions.java:212)
        at com.webobjects.appserver.WOComponent.valueForKeyPath(WOComponent.java:1804)
        at com.webobjects.appserver._private.WOKeyValueAssociation.valueInComponent(WOKeyValueAssociation.java:50)
        at com.webobjects.appserver._private.WOSubmitButton.invokeAction(WOSubmitButton.java:70)
        at er.extensions.foundation.ERXPatcher$DynamicElementsPatches$SubmitButton.invokeAction(ERXPatcher.java:214)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at er.extensions.components._private.ERXWOForm.invokeAction(ERXWOForm.java:180)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOComponentContent.invokeAction(WOComponentContent.java:38)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOConditional.invokeAction(WOConditional.java:86)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOHTMLURLValuedElement.invokeAction(WOHTMLURLValuedElement.java:149)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
        at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:92)
        at com.webobjects.appserver._private.WOComponentReference.invokeAction(WOComponentReference.java:127)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOConditional.invokeAction(WOConditional.java:86)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
        at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:92)
        at com.webobjects.appserver.WOSession.invokeAction(WOSession.java:1357)
        at Session.invokeAction(Session.java:195)
        at com.webobjects.appserver.WOApplication.invokeAction(WOApplication.java:1745)
        at er.extensions.appserver.ajax.ERXAjaxApplication.invokeAction(ERXAjaxApplication.java:50)
        at er.extensions.appserver.ERXApplication.invokeAction(ERXApplication.java:1687)
        at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedPage(WOComponentRequestHandler.java:206)
        at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedSession(WOComponentRequestHandler.java:298)
        at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedApplication(WOComponentRequestHandler.java:332)
        at com.webobjects.appserver._private.WOComponentRequestHandler._handleRequest(WOComponentRequestHandler.java:369)
        at com.webobjects.appserver._private.WOComponentRequestHandler.handleRequest(WOComponentRequestHandler.java:442)
        at com.webobjects.appserver.WOApplication.dispatchRequest(WOApplication.java:1687)
        at er.extensions.appserver.ERXApplication.dispatchRequestImmediately(ERXApplication.java:1802)
        at er.extensions.appserver.ERXApplication.dispatchRequest(ERXApplication.java:1767)
        at Application.dispatchRequest(Application.java:653)
        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:619)

12770695 [WorkerThread30] WARN er.extensions.eof.ERXEC  - 23398687 Attempting to lock editing context from WorkerThread30 that was previously locked in WorkerThread24
 Current stack trace: java.lang.Exception: Locked
        at er.extensions.eof.ERXEC.lock(ERXEC.java:448)
        at er.extensions.eof.ERXEC.autoLock(ERXEC.java:553)
        at er.extensions.eof.ERXEC.globalIDForObject(ERXEC.java:734)
        at com.webobjects.eoaccess.EOUtilities.primaryKeyForObject(EOUtilities.java:880)
        at GenericRecord.primaryKeyDictionary(GenericRecord.java:297)
        at GenericRecord.primaryKeyObject(GenericRecord.java:315)
        at GenericRecord.primaryKeyInt(GenericRecord.java:327)
        at Application.dispatchRequest(Application.java:661)
        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:619)

 Lock count: 1
 Existing lock: java.lang.Exception: Locked
        at er.extensions.eof.ERXEC.lock(ERXEC.java:448)
        at er.extensions.eof.ERXEC.autoLock(ERXEC.java:553)
        at er.extensions.eof.ERXEC.globalIDForObject(ERXEC.java:734)
        at com.webobjects.eoaccess.EOUtilities.primaryKeyForObject(EOUtilities.java:880)
        at GenericRecord.primaryKeyDictionary(GenericRecord.java:297)
        at GenericRecord.primaryKeyObject(GenericRecord.java:315)
        at GenericRecord.primaryKeyInt(GenericRecord.java:327)
        at Application.dispatchRequest(Application.java:661)
        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:619)
 Created: java.lang.Exception: Creation
        at er.extensions.eof.ERXEC.<init>(ERXEC.java:353)
        at er.extensions.eof.ERXEC$DefaultFactory._createEditingContext(ERXEC.java:1492)
        at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1455)
        at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1434)
        at er.extensions.eof.ERXEC.newEditingContext(ERXEC.java:1540)
        at er.extensions.appserver.ERXSession.defaultEditingContext(ERXSession.java:353)
        at Session.setLoginUser(Session.java:110)
        at Main.login(Main.java:185)
        at Main.login(Main.java:120)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
        at com.webobjects.foundation.NSKeyValueCoding$_MethodBinding.valueInObject(NSKeyValueCoding.java:1134)
        at com.webobjects.foundation.NSKeyValueCoding$DefaultImplementation.valueForKey(NSKeyValueCoding.java:1324)
        at com.webobjects.appserver.WOComponent.valueForKey(WOComponent.java:1736)
        at com.webobjects.foundation.NSKeyValueCoding$Utility.valueForKey(NSKeyValueCoding.java:447)
        at com.webobjects.foundation.NSKeyValueCodingAdditions$DefaultImplementation.valueForKeyPath(NSKeyValueCodingAdditions.java:212)
        at com.webobjects.appserver.WOComponent.valueForKeyPath(WOComponent.java:1804)
        at com.webobjects.appserver._private.WOKeyValueAssociation.valueInComponent(WOKeyValueAssociation.java:50)
        at com.webobjects.appserver._private.WOSubmitButton.invokeAction(WOSubmitButton.java:70)
        at er.extensions.foundation.ERXPatcher$DynamicElementsPatches$SubmitButton.invokeAction(ERXPatcher.java:214)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at er.extensions.components._private.ERXWOForm.invokeAction(ERXWOForm.java:180)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOComponentContent.invokeAction(WOComponentContent.java:38)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOConditional.invokeAction(WOConditional.java:86)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOHTMLURLValuedElement.invokeAction(WOHTMLURLValuedElement.java:149)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
        at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:92)
        at com.webobjects.appserver._private.WOComponentReference.invokeAction(WOComponentReference.java:127)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver._private.WOConditional.invokeAction(WOConditional.java:86)
        at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
        at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
        at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
        at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:92)
        at com.webobjects.appserver.WOSession.invokeAction(WOSession.java:1357)
        at Session.invokeAction(Session.java:195)
        at com.webobjects.appserver.WOApplication.invokeAction(WOApplication.java:1745)
        at er.extensions.appserver.ajax.ERXAjaxApplication.invokeAction(ERXAjaxApplication.java:50)
        at er.extensions.appserver.ERXApplication.invokeAction(ERXApplication.java:1687)
        at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedPage(WOComponentRequestHandler.java:206)
        at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedSession(WOComponentRequestHandler.java:298)
        at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedApplication(WOComponentRequestHandler.java:332)
        at com.webobjects.appserver._private.WOComponentRequestHandler._handleRequest(WOComponentRequestHandler.java:369)
        at com.webobjects.appserver._private.WOComponentRequestHandler.handleRequest(WOComponentRequestHandler.java:442)
        at com.webobjects.appserver.WOApplication.dispatchRequest(WOApplication.java:1687)
        at er.extensions.appserver.ERXApplication.dispatchRequestImmediately(ERXApplication.java:1802)
        at er.extensions.appserver.ERXApplication.dispatchRequest(ERXApplication.java:1767)
        at Application.dispatchRequest(Application.java:653)
        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:619)

12770707 [WorkerThread27] WARN er.extensions.eof.ERXEC  - Unlocking context that wasn't unlocked in RR-Loop!: er.extensions.eof.ERXEC@165091f

----------------------------------------------------------------
---------------------------------------------------------------

Regards,
Raghu.

On 21-Nov-2014, at 10:25 PM, Ralf Schuchardt wrote:

Hi Raghu,

as far as I can see, you have a log of lock/unlock operations with the EditingContext IDs and your original deadlock log with blocked thread names. But it is not easy to correlate those two logs, as the deadlock log is missing object IDs and the lock/unlock log has no thread names. I would expect there to be one more lock than unlock in the log, but it is tedious to find the right one.

There is the property "er.extensions.ERXEC.markOpenLocks" that may help, if you can get it to work. When the deadlock occurs the direct action "ERXDirectAction/showOpenEditingContextLockTraces" should show you a more complete picture of currently open locks and where the offending editing context was created.

Kind regards,
Ralf


Am 20.11.2014 um 15:23 schrieb Raghavender Bokka <email@hidden>:

Hi Team,

The following are the exceptions generating in the log files when we enable the ERX logging, and we do not have any code in the Session.sleep method. And some of our WebObjects application instances are hanging when some user load (around 1000 users) are testing, when we look into the java process thread dump there are deadlocks occurring.

-----------------------------------------------------------------------
-----------------------------------------------------------------------
Exception
at er.extensions.eof.ERXEC.unlock(ERXEC.java:501)
at com.webobjects.eocontrol.EOEditingContext._sendOrEnqueueNotification(EOEditingContext.java:4721)
at com.webobjects.eocontrol.EOEditingContext._objectsChangedInStore(EOEditingContext.java:3562)
at er.extensions.eof.ERXEC._objectsChangedInStore(ERXEC.java:1285)
  ... skipped 7 stack elements
at com.webobjects.eocontrol.EOObjectStoreCoordinator._objectsChangedInSubStore(EOObjectStoreCoordinator.java:693)
  ... skipped 16 stack elements
at com.webobjects.eocontrol.EOObjectStoreCoordinator.saveChangesInEditingContext(EOObjectStoreCoordinator.java:386)
at com.webobjects.eocontrol.EOEditingContext.saveChanges(EOEditingContext.java:3192)
at er.extensions.eof.ERXEC._saveChanges(ERXEC.java:981)
at er.extensions.eof.ERXEC.saveChanges(ERXEC.java:903)
at TestTakingMode$StudentTestSessionMode.testSubmitted(TestTakingMode.java:648)
at ReviewTestResponsePage.submitTest(ReviewTestResponsePage.java:99)
  ... skipped 4 stack elements
at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
  ... skipped 46 stack elements
at Application.dispatchRequest(Application.java:670)
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.appserver.ERXSession  - Will terminate, sessionId is FkDsWpsOxKy1TDaligNLDg
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.appserver.ERXBrowserFactory  - _incrementReferenceCounterForKey() - count = 26, key = IE.7.0.4.0.Windows.{cpu = "Unknown CPU"; geckoRevision = "No Gecko"; }
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After popping: [er.extensions.eof.ERXEC@dd151f]
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.ERXEC.LockLogger  - unlocked er.extensions.eof.ERXEC@13cd5b5
Exception
at er.extensions.eof.ERXEC.unlock(ERXEC.java:501)
at com.webobjects.appserver.WOSession._sleepInContext(WOSession.java:849)
at com.webobjects.appserver.WOApplication.saveSessionForContext(WOApplication.java:1883)
at er.extensions.appserver.ERXApplication.saveSessionForContext(ERXApplication.java:2075)
  ... skipped 6 stack elements
at Application.dispatchRequest(Application.java:670)
... skipped 3 stack elements
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.ERXEC.LockLogger  - locked er.extensions.eof.ERXEC@13cd5b5
Exception
at er.extensions.eof.ERXEC.lock(ERXEC.java:483)
at com.webobjects.eocontrol.EOEditingContext._dispose(EOEditingContext.java:1116)
at com.webobjects.eocontrol.EOEditingContext.dispose(EOEditingContext.java:1111)
at er.extensions.eof.ERXEC.dispose(ERXEC.java:610)
at com.webobjects.appserver.WOSession._sleepInContext(WOSession.java:854)
at com.webobjects.appserver.WOApplication.saveSessionForContext(WOApplication.java:1883)
at er.extensions.appserver.ERXApplication.saveSessionForContext(ERXApplication.java:2075)
  ... skipped 6 stack elements
at Application.dispatchRequest(Application.java:670)
... skipped 3 stack elements
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After pushing: [er.extensions.eof.ERXEC@dd151f, er.extensions.eof.ERXEC@13cd5b5]
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After popping: [er.extensions.eof.ERXEC@dd151f]
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.ERXEC.LockLogger  - unlocked er.extensions.eof.ERXEC@13cd5b5
Exception
at er.extensions.eof.ERXEC.unlock(ERXEC.java:501)
at com.webobjects.eocontrol.EOEditingContext._dispose(EOEditingContext.java:1218)
at com.webobjects.eocontrol.EOEditingContext.dispose(EOEditingContext.java:1111)
at er.extensions.eof.ERXEC.dispose(ERXEC.java:610)
at com.webobjects.appserver.WOSession._sleepInContext(WOSession.java:854)
at com.webobjects.appserver.WOApplication.saveSessionForContext(WOApplication.java:1883)
at er.extensions.appserver.ERXApplication.saveSessionForContext(ERXApplication.java:2075)
  ... skipped 6 stack elements
at Application.dispatchRequest(Application.java:670)
... skipped 3 stack elements
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After pushing: [er.extensions.eof.ERXEC@dd151f, er.extensions.eof.ERXEC@dd151f]
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After popping: [er.extensions.eof.ERXEC@dd151f]
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.appserver.ERXBrowserFactory  - _decrementReferenceCounterForKey() - count = 25, key = IE.7.0.4.0.Windows.{cpu = "Unknown CPU"; geckoRevision = "No Gecko"; }
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.appserver.ERXBrowserFactory  - _decrementReferenceCounterForKey() - count = 15, key = IE.9.0.5.0.Windows.{cpu = "Unknown CPU"; geckoRevision = "No Gecko"; }
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - Unlock remaining: [er.extensions.eof.ERXEC@dd151f]
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - Unlocking autolocked editing context: er.extensions.eof.ERXEC@dd151f
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.appserver.ERXBrowserFactory  - _decrementReferenceCounterForKey() - count = 24, key = IE.7.0.4.0.Windows.{cpu = "Unknown CPU"; geckoRevision = "No Gecko"; }

-----------------------------------------------------------------------
-----------------------------------------------------------------------

Nov 17 22:20:58 Solar[6009] DEBUG er.extensions.ERXEC.LockLogger  - locked er.extensions.eof.ERXEC@13cd5b5
Exception
at er.extensions.eof.ERXEC.lock(ERXEC.java:483)
at com.webobjects.appserver.WOSession._awakeInContext(WOSession.java:835)
at com.webobjects.appserver.WOApplication.restoreSessionWithID(WOApplication.java:1917)
at er.extensions.appserver.ERXApplication.restoreSessionWithID(ERXApplication.java:2093)
  ... skipped 6 stack elements
at Application.dispatchRequest(Application.java:670)
... skipped 3 stack elements
Nov 17 22:20:58 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After pushing: [er.extensions.eof.ERXEC@13cd5b5]
Nov 17 22:20:58 Solar[6009] DEBUG er.extensions.eof.ERXEC$DefaultFactory  - Setting default delegate on editing context: er.extensions.eof.ERXEC@1a3b17a allows validation: true
Nov 17 22:20:58 Solar[6009] DEBUG er.extensions.eof.ERXEC  - setting delegate to er.extensions.eof.ERXDefaultEditingContextDelegate@e93999
Nov 17 22:20:58 Solar[6009] DEBUG er.extensions.eof.ERXEC  - s.java:375)
     at er.extensions.eof.ERXEC.setDelegate(ERXEC.java:1312)
     at er.extensions.eof.ERXEC$DefaultFactory.setDefaultDelegateOnEditingContext(ERXEC.java:1408)
     at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1463)
     at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1434)
     at er.extensions.eof.ERXEC.newEditingContext(ERXEC.java:1540)
     at GenericComponent.localEditingContext(GenericComponent.java:75)
     at SelectTestPage.fetchTests(SelectTestPage.java:71)
     at SelectTestPage.selectNonDOETests(SelectTestPage.java:146)
     at ToolsHelperFrame.selectTestPageFrame(ToolsHelperFrame.java:29)
     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
     at java.lang.reflect.Method.invoke(Method.java:597)
     at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
     at com.webobjects.foundation.NSKeyValueCoding$_MethodBinding.valueInObject(NSKeyValueCoding.java:1134)
     at com.webobjects.foundation.NSKeyValueCoding$DefaultImplementation.valueForKey(NSKeyValueCoding.java:1324)
     at com.webobjects.appserver.WOComponent.valueForKey(WOComponent.java:1736)
     at com.webobjects.foundation.NSKeyValueCoding$Utility.valueForKey(NSKeyValueCoding.java:447)
     at com.webobjects.foundation.NSKeyValueCodingAdditions$DefaultImplementation.valueForKeyPath(NSKeyValueCodingAdditions.java:212)
     at com.webobjects.appserver.WOComponent.valueForKeyPath(WOComponent.java:1804)
     at com.webobjects.appserver._private.WOKeyValueAssociation.valueInComponent(WOKeyValueAssociation.java:50)
     at com.webobjects.appserver._private.WOHTMLURLValuedElement.invokeAction(WOHTMLURLValuedElement.java:138)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
     at com.webobjects.appserver.WOSession.invokeAction(WOSession.java:1357)
     at Session.invokeAction(Session.java:191)
     at com.webobjects.appserver.WOApplication.invokeAction(WOApplication.java:1745)
     at er.extensions.appserver.ajax.ERXAjaxApplication.invokeAction(ERXAjaxApplication.java:50)
     at er.extensions.appserver.ERXApplication.invokeAction(ERXApplication.java:1687)
     at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedPage(WOComponentRequestHandler.java:206)
     at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedSession(WOComponentRequestHandler.java:298)
     at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedApplication(WOComponentRequestHandler.java:332)
     at com.webobjects.appserver._private.WOComponentRequestHandler._handleRequest(WOComponentRequestHandler.java:369)
     at com.webobjects.appserver._private.WOComponentRequestHandler.handleRequest(WOComponentRequestHandler.java:442)
     at com.webobjects.appserver.WOApplication.dispatchRequest(WOApplication.java:1687)
     at er.extensions.appserver.ERXApplication.dispatchRequestImmediately(ERXApplication.java:1802)
     at er.extensions.appserver.ERXApplication.dispatchRequest(ERXApplication.java:1767)
     at Application.dispatchRequest(Application.java:670)
     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:619)


Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.eof.ERXEC$DefaultFactory  - Setting default delegate on editing context: er.extensions.eof.ERXEC@13cd5b5 allows validation: true
Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.eof.ERXEC  - setting delegate to er.extensions.eof.ERXDefaultEditingContextDelegate@e93999
Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.eof.ERXEC  - s.java:375)
     at er.extensions.eof.ERXEC.setDelegate(ERXEC.java:1312)
     at er.extensions.eof.ERXEC$DefaultFactory.setDefaultDelegateOnEditingContext(ERXEC.java:1408)
     at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1463)
     at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1434)
     at er.extensions.eof.ERXEC.newEditingContext(ERXEC.java:1540)
     at er.extensions.appserver.ERXSession.defaultEditingContext(ERXSession.java:353)
     at Session.setLoginUser(Session.java:106)
     at Main.login(Main.java:185)
     at Main.login(Main.java:120)
     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
     at java.lang.reflect.Method.invoke(Method.java:597)
     at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
     at com.webobjects.foundation.NSKeyValueCoding$_MethodBinding.valueInObject(NSKeyValueCoding.java:1134)
     at com.webobjects.foundation.NSKeyValueCoding$DefaultImplementation.valueForKey(NSKeyValueCoding.java:1324)
     at com.webobjects.appserver.WOComponent.valueForKey(WOComponent.java:1736)
     at com.webobjects.foundation.NSKeyValueCoding$Utility.valueForKey(NSKeyValueCoding.java:447)
     at com.webobjects.foundation.NSKeyValueCodingAdditions$DefaultImplementation.valueForKeyPath(NSKeyValueCodingAdditions.java:212)
     at com.webobjects.appserver.WOComponent.valueForKeyPath(WOComponent.java:1804)
     at com.webobjects.appserver._private.WOKeyValueAssociation.valueInComponent(WOKeyValueAssociation.java:50)
     at com.webobjects.appserver._private.WOSubmitButton.invokeAction(WOSubmitButton.java:70)
     at er.extensions.foundation.ERXPatcher$DynamicElementsPatches$SubmitButton.invokeAction(ERXPatcher.java:214)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at er.extensions.components._private.ERXWOForm.invokeAction(ERXWOForm.java:180)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver._private.WOComponentContent.invokeAction(WOComponentContent.java:38)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver._private.WOConditional.invokeAction(WOConditional.java:86)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver._private.WOHTMLURLValuedElement.invokeAction(WOHTMLURLValuedElement.java:149)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
     at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:92)
     at com.webobjects.appserver._private.WOComponentReference.invokeAction(WOComponentReference.java:127)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver._private.WOConditional.invokeAction(WOConditional.java:86)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
     at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:92)
     at com.webobjects.appserver.WOSession.invokeAction(WOSession.java:1357)
     at Session.invokeAction(Session.java:191)
     at com.webobjects.appserver.WOApplication.invokeAction(WOApplication.java:1745)
     at er.extensions.appserver.ajax.ERXAjaxApplication.invokeAction(ERXAjaxApplication.java:50)
     at er.extensions.appserver.ERXApplication.invokeAction(ERXApplication.java:1687)
     at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedPage(WOComponentRequestHandler.java:206)
     at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedSession(WOComponentRequestHandler.java:298)
     at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedApplication(WOComponentRequestHandler.java:332)
     at com.webobjects.appserver._private.WOComponentRequestHandler._handleRequest(WOComponentRequestHandler.java:369)
     at com.webobjects.appserver._private.WOComponentRequestHandler.handleRequest(WOComponentRequestHandler.java:442)
     at com.webobjects.appserver.WOApplication.dispatchRequest(WOApplication.java:1687)
     at er.extensions.appserver.ERXApplication.dispatchRequestImmediately(ERXApplication.java:1802)
     at er.extensions.appserver.ERXApplication.dispatchRequest(ERXApplication.java:1767)
     at Application.dispatchRequest(Application.java:653)
     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:619)

Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.ERXEC.LockLogger  - locked er.extensions.eof.ERXEC@13cd5b5
Exception
at er.extensions.eof.ERXEC.lock(ERXEC.java:483)
at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1465)
at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1434)
at er.extensions.eof.ERXEC.newEditingContext(ERXEC.java:1540)
at er.extensions.appserver.ERXSession.defaultEditingContext(ERXSession.java:353)
at Session.setLoginUser(Session.java:106)
at Main.login(Main.java:185)
at Main.login(Main.java:120)
  ... skipped 4 stack elements
at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
  ... skipped 46 stack elements
at Application.dispatchRequest(Application.java:653)
... skipped 3 stack elements
Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After pushing: [er.extensions.eof.ERXEC@5971c3, er.extensions.eof.ERXEC@13cd5b5]
Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After popping: [er.extensions.eof.ERXEC@5971c3]
Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.ERXEC.LockLogger  - unlocked er.extensions.eof.ERXEC@13cd5b5
Exception
at er.extensions.eof.ERXEC.unlock(ERXEC.java:501)
at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1467)
at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1434)
at er.extensions.eof.ERXEC.newEditingContext(ERXEC.java:1540)
at er.extensions.appserver.ERXSession.defaultEditingContext(ERXSession.java:353)
at Session.setLoginUser(Session.java:106)
at Main.login(Main.java:185)
at Main.login(Main.java:120)
  ... skipped 4 stack elements
at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
  ... skipped 46 stack elements
at Application.dispatchRequest(Application.java:653)
... skipped 3 stack elements
-----------------------------------------------------------------------
-----------------------------------------------------------------------

Any help would be appreciated.

Regards,
Raghu.
On 18-Nov-2014, at 5:08 PM, email@hidden wrote:



-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.apple.com/archives/webobjects-dev/attachments/20141117/cdcbcb11/attachment.html>

------------------------------

Message: 4
Date: Tue, 18 Nov 2014 17:09:40 +0530
From: Raghavender Bokka <email@hidden>
To: Ralf Schuchardt <email@hidden>,    Development WebObjects
    <email@hidden>
Cc: Sudhakar Madala <email@hidden>,    "Mr. Ernie
    Satterwhite" <email@hidden>,    "Vicky C. Miller"
    <email@hidden>
Subject: Re: WebObjects application instances hanging - Deadlocks
    occurring
Message-ID:
    <email@hidden">email@hidden>
Content-Type: text/plain; charset=us-ascii

Hi Ralf,

The following are the exceptions generating in the log files when we enable the ERX logging, and we do not have any code in the Session.sleep method:

-----------------------------------------------------------------------
-----------------------------------------------------------------------
Exception
at er.extensions.eof.ERXEC.unlock(ERXEC.java:501)
at com.webobjects.eocontrol.EOEditingContext._sendOrEnqueueNotification(EOEditingContext.java:4721)
at com.webobjects.eocontrol.EOEditingContext._objectsChangedInStore(EOEditingContext.java:3562)
at er.extensions.eof.ERXEC._objectsChangedInStore(ERXEC.java:1285)
  ... skipped 7 stack elements
at com.webobjects.eocontrol.EOObjectStoreCoordinator._objectsChangedInSubStore(EOObjectStoreCoordinator.java:693)
  ... skipped 16 stack elements
at com.webobjects.eocontrol.EOObjectStoreCoordinator.saveChangesInEditingContext(EOObjectStoreCoordinator.java:386)
at com.webobjects.eocontrol.EOEditingContext.saveChanges(EOEditingContext.java:3192)
at er.extensions.eof.ERXEC._saveChanges(ERXEC.java:981)
at er.extensions.eof.ERXEC.saveChanges(ERXEC.java:903)
at TestTakingMode$StudentTestSessionMode.testSubmitted(TestTakingMode.java:648)
at ReviewTestResponsePage.submitTest(ReviewTestResponsePage.java:99)
  ... skipped 4 stack elements
at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
  ... skipped 46 stack elements
at Application.dispatchRequest(Application.java:670)
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.appserver.ERXSession  - Will terminate, sessionId is FkDsWpsOxKy1TDaligNLDg
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.appserver.ERXBrowserFactory  - _incrementReferenceCounterForKey() - count = 26, key = IE.7.0.4.0.Windows.{cpu = "Unknown CPU"; geckoRevision = "No Gecko"; }
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After popping: [er.extensions.eof.ERXEC@dd151f]
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.ERXEC.LockLogger  - unlocked er.extensions.eof.ERXEC@13cd5b5
Exception
at er.extensions.eof.ERXEC.unlock(ERXEC.java:501)
at com.webobjects.appserver.WOSession._sleepInContext(WOSession.java:849)
at com.webobjects.appserver.WOApplication.saveSessionForContext(WOApplication.java:1883)
at er.extensions.appserver.ERXApplication.saveSessionForContext(ERXApplication.java:2075)
  ... skipped 6 stack elements
at Application.dispatchRequest(Application.java:670)
... skipped 3 stack elements
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.ERXEC.LockLogger  - locked er.extensions.eof.ERXEC@13cd5b5
Exception
at er.extensions.eof.ERXEC.lock(ERXEC.java:483)
at com.webobjects.eocontrol.EOEditingContext._dispose(EOEditingContext.java:1116)
at com.webobjects.eocontrol.EOEditingContext.dispose(EOEditingContext.java:1111)
at er.extensions.eof.ERXEC.dispose(ERXEC.java:610)
at com.webobjects.appserver.WOSession._sleepInContext(WOSession.java:854)
at com.webobjects.appserver.WOApplication.saveSessionForContext(WOApplication.java:1883)
at er.extensions.appserver.ERXApplication.saveSessionForContext(ERXApplication.java:2075)
  ... skipped 6 stack elements
at Application.dispatchRequest(Application.java:670)
... skipped 3 stack elements
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After pushing: [er.extensions.eof.ERXEC@dd151f, er.extensions.eof.ERXEC@13cd5b5]
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After popping: [er.extensions.eof.ERXEC@dd151f]
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.ERXEC.LockLogger  - unlocked er.extensions.eof.ERXEC@13cd5b5
Exception
at er.extensions.eof.ERXEC.unlock(ERXEC.java:501)
at com.webobjects.eocontrol.EOEditingContext._dispose(EOEditingContext.java:1218)
at com.webobjects.eocontrol.EOEditingContext.dispose(EOEditingContext.java:1111)
at er.extensions.eof.ERXEC.dispose(ERXEC.java:610)
at com.webobjects.appserver.WOSession._sleepInContext(WOSession.java:854)
at com.webobjects.appserver.WOApplication.saveSessionForContext(WOApplication.java:1883)
at er.extensions.appserver.ERXApplication.saveSessionForContext(ERXApplication.java:2075)
  ... skipped 6 stack elements
at Application.dispatchRequest(Application.java:670)
... skipped 3 stack elements
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After pushing: [er.extensions.eof.ERXEC@dd151f, er.extensions.eof.ERXEC@dd151f]
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After popping: [er.extensions.eof.ERXEC@dd151f]
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.appserver.ERXBrowserFactory  - _decrementReferenceCounterForKey() - count = 25, key = IE.7.0.4.0.Windows.{cpu = "Unknown CPU"; geckoRevision = "No Gecko"; }
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.appserver.ERXBrowserFactory  - _decrementReferenceCounterForKey() - count = 15, key = IE.9.0.5.0.Windows.{cpu = "Unknown CPU"; geckoRevision = "No Gecko"; }
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - Unlock remaining: [er.extensions.eof.ERXEC@dd151f]
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.eof.ERXEC  - Unlocking autolocked editing context: er.extensions.eof.ERXEC@dd151f
Nov 17 22:22:01 Solar[6009] DEBUG er.extensions.appserver.ERXBrowserFactory  - _decrementReferenceCounterForKey() - count = 24, key = IE.7.0.4.0.Windows.{cpu = "Unknown CPU"; geckoRevision = "No Gecko"; }

-----------------------------------------------------------------------
-----------------------------------------------------------------------

Nov 17 22:20:58 Solar[6009] DEBUG er.extensions.ERXEC.LockLogger  - locked er.extensions.eof.ERXEC@13cd5b5
Exception
at er.extensions.eof.ERXEC.lock(ERXEC.java:483)
at com.webobjects.appserver.WOSession._awakeInContext(WOSession.java:835)
at com.webobjects.appserver.WOApplication.restoreSessionWithID(WOApplication.java:1917)
at er.extensions.appserver.ERXApplication.restoreSessionWithID(ERXApplication.java:2093)
  ... skipped 6 stack elements
at Application.dispatchRequest(Application.java:670)
... skipped 3 stack elements
Nov 17 22:20:58 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After pushing: [er.extensions.eof.ERXEC@13cd5b5]
Nov 17 22:20:58 Solar[6009] DEBUG er.extensions.eof.ERXEC$DefaultFactory  - Setting default delegate on editing context: er.extensions.eof.ERXEC@1a3b17a allows validation: true
Nov 17 22:20:58 Solar[6009] DEBUG er.extensions.eof.ERXEC  - setting delegate to er.extensions.eof.ERXDefaultEditingContextDelegate@e93999
Nov 17 22:20:58 Solar[6009] DEBUG er.extensions.eof.ERXEC  - s.java:375)
     at er.extensions.eof.ERXEC.setDelegate(ERXEC.java:1312)
     at er.extensions.eof.ERXEC$DefaultFactory.setDefaultDelegateOnEditingContext(ERXEC.java:1408)
     at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1463)
     at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1434)
     at er.extensions.eof.ERXEC.newEditingContext(ERXEC.java:1540)
     at GenericComponent.localEditingContext(GenericComponent.java:75)
     at SelectTestPage.fetchTests(SelectTestPage.java:71)
     at SelectTestPage.selectNonDOETests(SelectTestPage.java:146)
     at ToolsHelperFrame.selectTestPageFrame(ToolsHelperFrame.java:29)
     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
     at java.lang.reflect.Method.invoke(Method.java:597)
     at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
     at com.webobjects.foundation.NSKeyValueCoding$_MethodBinding.valueInObject(NSKeyValueCoding.java:1134)
     at com.webobjects.foundation.NSKeyValueCoding$DefaultImplementation.valueForKey(NSKeyValueCoding.java:1324)
     at com.webobjects.appserver.WOComponent.valueForKey(WOComponent.java:1736)
     at com.webobjects.foundation.NSKeyValueCoding$Utility.valueForKey(NSKeyValueCoding.java:447)
     at com.webobjects.foundation.NSKeyValueCodingAdditions$DefaultImplementation.valueForKeyPath(NSKeyValueCodingAdditions.java:212)
     at com.webobjects.appserver.WOComponent.valueForKeyPath(WOComponent.java:1804)
     at com.webobjects.appserver._private.WOKeyValueAssociation.valueInComponent(WOKeyValueAssociation.java:50)
     at com.webobjects.appserver._private.WOHTMLURLValuedElement.invokeAction(WOHTMLURLValuedElement.java:138)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
     at com.webobjects.appserver.WOSession.invokeAction(WOSession.java:1357)
     at Session.invokeAction(Session.java:191)
     at com.webobjects.appserver.WOApplication.invokeAction(WOApplication.java:1745)
     at er.extensions.appserver.ajax.ERXAjaxApplication.invokeAction(ERXAjaxApplication.java:50)
     at er.extensions.appserver.ERXApplication.invokeAction(ERXApplication.java:1687)
     at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedPage(WOComponentRequestHandler.java:206)
     at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedSession(WOComponentRequestHandler.java:298)
     at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedApplication(WOComponentRequestHandler.java:332)
     at com.webobjects.appserver._private.WOComponentRequestHandler._handleRequest(WOComponentRequestHandler.java:369)
     at com.webobjects.appserver._private.WOComponentRequestHandler.handleRequest(WOComponentRequestHandler.java:442)
     at com.webobjects.appserver.WOApplication.dispatchRequest(WOApplication.java:1687)
     at er.extensions.appserver.ERXApplication.dispatchRequestImmediately(ERXApplication.java:1802)
     at er.extensions.appserver.ERXApplication.dispatchRequest(ERXApplication.java:1767)
     at Application.dispatchRequest(Application.java:670)
     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:619)


Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.eof.ERXEC$DefaultFactory  - Setting default delegate on editing context: er.extensions.eof.ERXEC@13cd5b5 allows validation: true
Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.eof.ERXEC  - setting delegate to er.extensions.eof.ERXDefaultEditingContextDelegate@e93999
Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.eof.ERXEC  - s.java:375)
     at er.extensions.eof.ERXEC.setDelegate(ERXEC.java:1312)
     at er.extensions.eof.ERXEC$DefaultFactory.setDefaultDelegateOnEditingContext(ERXEC.java:1408)
     at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1463)
     at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1434)
     at er.extensions.eof.ERXEC.newEditingContext(ERXEC.java:1540)
     at er.extensions.appserver.ERXSession.defaultEditingContext(ERXSession.java:353)
     at Session.setLoginUser(Session.java:106)
     at Main.login(Main.java:185)
     at Main.login(Main.java:120)
     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
     at java.lang.reflect.Method.invoke(Method.java:597)
     at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
     at com.webobjects.foundation.NSKeyValueCoding$_MethodBinding.valueInObject(NSKeyValueCoding.java:1134)
     at com.webobjects.foundation.NSKeyValueCoding$DefaultImplementation.valueForKey(NSKeyValueCoding.java:1324)
     at com.webobjects.appserver.WOComponent.valueForKey(WOComponent.java:1736)
     at com.webobjects.foundation.NSKeyValueCoding$Utility.valueForKey(NSKeyValueCoding.java:447)
     at com.webobjects.foundation.NSKeyValueCodingAdditions$DefaultImplementation.valueForKeyPath(NSKeyValueCodingAdditions.java:212)
     at com.webobjects.appserver.WOComponent.valueForKeyPath(WOComponent.java:1804)
     at com.webobjects.appserver._private.WOKeyValueAssociation.valueInComponent(WOKeyValueAssociation.java:50)
     at com.webobjects.appserver._private.WOSubmitButton.invokeAction(WOSubmitButton.java:70)
     at er.extensions.foundation.ERXPatcher$DynamicElementsPatches$SubmitButton.invokeAction(ERXPatcher.java:214)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at er.extensions.components._private.ERXWOForm.invokeAction(ERXWOForm.java:180)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver._private.WOComponentContent.invokeAction(WOComponentContent.java:38)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver._private.WOConditional.invokeAction(WOConditional.java:86)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver._private.WOHTMLURLValuedElement.invokeAction(WOHTMLURLValuedElement.java:149)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
     at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:92)
     at com.webobjects.appserver._private.WOComponentReference.invokeAction(WOComponentReference.java:127)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver._private.WOConditional.invokeAction(WOConditional.java:86)
     at com.webobjects.appserver._private.WODynamicGroup.invokeChildrenAction(WODynamicGroup.java:105)
     at com.webobjects.appserver._private.WODynamicGroup.invokeAction(WODynamicGroup.java:115)
     at com.webobjects.appserver.WOComponent.invokeAction(WOComponent.java:1079)
     at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:92)
     at com.webobjects.appserver.WOSession.invokeAction(WOSession.java:1357)
     at Session.invokeAction(Session.java:191)
     at com.webobjects.appserver.WOApplication.invokeAction(WOApplication.java:1745)
     at er.extensions.appserver.ajax.ERXAjaxApplication.invokeAction(ERXAjaxApplication.java:50)
     at er.extensions.appserver.ERXApplication.invokeAction(ERXApplication.java:1687)
     at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedPage(WOComponentRequestHandler.java:206)
     at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedSession(WOComponentRequestHandler.java:298)
     at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedApplication(WOComponentRequestHandler.java:332)
     at com.webobjects.appserver._private.WOComponentRequestHandler._handleRequest(WOComponentRequestHandler.java:369)
     at com.webobjects.appserver._private.WOComponentRequestHandler.handleRequest(WOComponentRequestHandler.java:442)
     at com.webobjects.appserver.WOApplication.dispatchRequest(WOApplication.java:1687)
     at er.extensions.appserver.ERXApplication.dispatchRequestImmediately(ERXApplication.java:1802)
     at er.extensions.appserver.ERXApplication.dispatchRequest(ERXApplication.java:1767)
     at Application.dispatchRequest(Application.java:653)
     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:619)

Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.ERXEC.LockLogger  - locked er.extensions.eof.ERXEC@13cd5b5
Exception
at er.extensions.eof.ERXEC.lock(ERXEC.java:483)
at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1465)
at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1434)
at er.extensions.eof.ERXEC.newEditingContext(ERXEC.java:1540)
at er.extensions.appserver.ERXSession.defaultEditingContext(ERXSession.java:353)
at Session.setLoginUser(Session.java:106)
at Main.login(Main.java:185)
at Main.login(Main.java:120)
  ... skipped 4 stack elements
at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
  ... skipped 46 stack elements
at Application.dispatchRequest(Application.java:653)
... skipped 3 stack elements
Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After pushing: [er.extensions.eof.ERXEC@5971c3, er.extensions.eof.ERXEC@13cd5b5]
Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.eof.ERXEC  - After popping: [er.extensions.eof.ERXEC@5971c3]
Nov 17 22:20:48 Solar[6009] DEBUG er.extensions.ERXEC.LockLogger  - unlocked er.extensions.eof.ERXEC@13cd5b5
Exception
at er.extensions.eof.ERXEC.unlock(ERXEC.java:501)
at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1467)
at er.extensions.eof.ERXEC$DefaultFactory._newEditingContext(ERXEC.java:1434)
at er.extensions.eof.ERXEC.newEditingContext(ERXEC.java:1540)
at er.extensions.appserver.ERXSession.defaultEditingContext(ERXSession.java:353)
at Session.setLoginUser(Session.java:106)
at Main.login(Main.java:185)
at Main.login(Main.java:120)
  ... skipped 4 stack elements
at KeyValueCodingProtectedAccessor.methodValue(KeyValueCodingProtectedAccessor.java:60)
  ... skipped 46 stack elements
at Application.dispatchRequest(Application.java:653)
... skipped 3 stack elements
-----------------------------------------------------------------------
-----------------------------------------------------------------------

Any help would be appreciated.

Regards,
Raghu.


Date: Mon, 17 Nov 2014 15:03:44 +0100
From: Ralf Schuchardt <email@hidden>
To: Development WebObjects <email@hidden>
Subject: Re: WebObjects application instances hanging - Deadlocks
    occurring
Message-ID: <email@hidden">email@hidden>
Content-Type: text/plain; charset=us-ascii

Hi,

Am 17.11.2014 um 13:33 schrieb Raghavender Bokka <email@hidden>:

Hi Team,

Some of our WebObjects application instances are hanging when some user load (around 1000 users) are testing, when we look into the java process thread dump there are deadlocks occurring. The following is the thread dump:

[...]

"WorkerThread24" prio=3 tid=0x00e42800 nid=0x31 waiting on condition [0xd49fe000]
java.lang.Thread.State: WAITING (parking)
   at sun.misc.Unsafe.park(Native Method)
   - parking to wait for  <0xdc3837c8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
   at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:747)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:778)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1114)
   at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:186)
   at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:262)
   at com.webobjects.eocontrol.EOEditingContext.lock(EOEditingContext.java:4617)
   at er.extensions.eof.ERXEC.lock(ERXEC.java:480)
   at com.webobjects.appserver.WOSession._awakeInContext(WOSession.java:835)
   at com.webobjects.appserver.WOApplication.restoreSessionWithID(WOApplication.java:1917)
   at er.extensions.appserver.ERXApplication.restoreSessionWithID(ERXApplication.java:2093)
   at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedApplication(WOComponentRequestHandler.java:324)
   at com.webobjects.appserver._private.WOComponentRequestHandler._handleRequest(WOComponentRequestHandler.java:369)
   at com.webobjects.appserver._private.WOComponentRequestHandler.handleRequest(WOComponentRequestHandler.java:442)
   - locked <0xdbc631d0> (a java.lang.Object)
   at com.webobjects.appserver.WOApplication.dispatchRequest(WOApplication.java:1687)
   at er.extensions.appserver.ERXApplication.dispatchRequestImmediately(ERXApplication.java:1802)
   at er.extensions.appserver.ERXApplication.dispatchRequest(ERXApplication.java:1767)
   at Application.dispatchRequest(Application.java:670)
   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:619)

This stack trace seems to indicate, that the defaultEditingContext was not unlocked in the previous request. Do you see an exception prior to the deadlock?
If you have code in a Session.sleep() method, make sure to catch all exceptions there.

Ralf



 
 _______________________________________________
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
  • Follow-Ups:
    • Re: WebObjects application instances hanging - Deadlocks occurring
      • From: Raghavender Reddy <email@hidden>
References: 
 >Re: WebObjects application instances hanging - Deadlocks occurring (From: Raghavender Reddy <email@hidden>)

  • Prev by Date: Re: WebObjects application instances hanging - Deadlocks occurring
  • Next by Date: Re: WebObjects application instances hanging - Deadlocks occurring
  • Previous by thread: Re: WebObjects application instances hanging - Deadlocks occurring
  • Next by thread: Re: WebObjects application instances hanging - Deadlocks occurring
  • Index(es):
    • Date
    • Thread