Re: production hanging
Re: production hanging
- Subject: Re: production hanging
- From: Chuck Hill <email@hidden>
- Date: Fri, 30 Nov 2012 13:48:09 -0800
On 2012-11-30, at 10:25 AM, Michael Gargano wrote:
> okay guys,
>
> you were right... it's a deadlock.... the worst of all possible worlds.
Actually, they are kind of fun to debug.
WorkerThread68 is the read problem indicator. WorkerThread255 is waiting on it. WorkerThread68 is waiting on
> - parking to wait for <0x00000007409438e0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
> at java.util.concurrent.locks.LockSupport.park(Unknown Source)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(Unknown Source)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Unknown Source)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(Unknown Source)
> at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(Unknown Source)
> at java.util.concurrent.locks.ReentrantLock.lock(Unknown Source)
> at com.webobjects.eocontrol.EOObjectStoreCoordinator.lock(EOObjectStoreCoordinator.java:420)
So some other thread has locked the OSC and then failed to unlock it. Probably due to faulty exception handling. Does anything in your code, anywhere, do explicity locking of the OSC or DB Context? If so, take a long hard look at it.
> I've included the trace below for one of the deadlocks. I keep getting two deadlocks at the time the app goes down. I can't quite figure out why, it seems like it's always in the same one or two places, but there's nothing so different about those spots that it shouldn't lock for the same reasons in a million other places in the app.
The bug is not in these traces. The thread holding the OSC lock is idle or doing something else. You are left with only the symptoms.
> I'm only doing fetches in these methods where it breaks and my guess is, that since I have 4 coordinators going, the four threads involved (between the two deadlocks) are locking the coordinators and bringing all the other threads to a grinding halt. It almost looks to me like a bug in the auto-locking.
Autolocking of the OSC or the EC? I doubt that EC auto locking is buggy.
> Can one thread be accessing multiple coordinators?
It is possible.
> I almost feel like one of the EOs I'm getting out of my default session store, that is being used in a fetch spec with an EO from the editing context on the page, are locking across two different store coordinators. Any help, as usual, is greatly appreciated. Thanks.
Worth looking at.
Chuck
>
> Found one Java-level deadlock:
> =============================
> "WorkerThread255":
> waiting for ownable synchronizer 0x0000000750171ce0, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
> which is held by "WorkerThread68"
> "WorkerThread68":
> waiting for ownable synchronizer 0x00000007409438e0, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
> which is held by "WorkerThread255"
>
> Java stack information for the threads listed above:
> ===================================================
> "WorkerThread255":
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x0000000750171ce0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
> at java.util.concurrent.locks.LockSupport.park(Unknown Source)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(Unknown Source)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Unknown Source)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(Unknown Source)
> at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(Unknown Source)
> at java.util.concurrent.locks.ReentrantLock.lock(Unknown Source)
> at com.webobjects.eocontrol.EOEditingContext.lock(EOEditingContext.java:4617)
> at er.extensions.eof.ERXEC.lock(ERXEC.java:514)
> at er.extensions.eof.ERXEC.autoLock(ERXEC.java:636)
> at er.extensions.eof.ERXEC.initializeObject(ERXEC.java:1143)
> at com.webobjects.eoaccess.EODatabaseContext._fireFault(EODatabaseContext.java:4124)
> at com.webobjects.eoaccess.EOAccessFaultHandler.completeInitializationOfObject(EOAccessFaultHandler.java:89)
> at com.webobjects.eocontrol.EOCustomObject.willRead(EOCustomObject.java:1172)
> at com.webobjects.eocontrol._EOMutableKnownKeyDictionary$Initializer$_GenericRecordBinding.valueInObject(_EOMutableKnownKeyDictionary.java:570)
> at com.webobjects.eocontrol._EOMutableKnownKeyDictionary$Initializer$_LazyGenericRecordBinding.valueInObject(_EOMutableKnownKeyDictionary.java:613)
> at er.extensions.eof.ERXGenericRecord$TouchingBinding.valueInObject(ERXGenericRecord.java:205)
> at com.webobjects.eocontrol.EOCustomObject.storedValueForKey(EOCustomObject.java:1634)
> at com.theapp.security.model._EGMUser.role(Unknown Source)
> at com.theapp.components.Nav.myLocker(Unknown Source)
> at sun.reflect.GeneratedMethodAccessor654.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
> at java.lang.reflect.Method.invoke(Unknown Source)
> at com.webobjects.foundation.NSKeyValueCoding$ValueAccessor$1.methodValue(NSKeyValueCoding.java:636)
> 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.WOHyperlink.invokeAction(WOHyperlink.java:98)
> at er.extensions.components._private.ERXHyperlink.invokeAction(ERXHyperlink.java:66)
> 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.WOComponent.invokeAction(WOComponent.java:1079)
> 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.WOComponent.invokeAction(WOComponent.java:1079)
> at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:102)
> 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.WOComponent.invokeAction(WOComponent.java:1079)
> at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:102)
> 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.WOGenericContainer.invokeAction(WOGenericContainer.java:29)
> 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._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.WOComponent.invokeAction(WOComponent.java:1079)
> at er.extensions.components.ERXComponent.invokeAction(ERXComponent.java:102)
> at com.webobjects.appserver.WOSession.invokeAction(WOSession.java:1357)
> at com.webobjects.appserver.WOApplication.invokeAction(WOApplication.java:1745)
> at er.extensions.appserver.ajax.ERXAjaxApplication.invokeAction(ERXAjaxApplication.java:95)
> at er.extensions.appserver.ERXApplication.invokeAction(ERXApplication.java:1906)
> 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:445)
> at com.webobjects.appserver.WOApplication.dispatchRequest(WOApplication.java:1687)
> at er.extensions.appserver.ERXApplication.dispatchRequestImmediately(ERXApplication.java:2021)
> at er.extensions.appserver.ERXApplication.dispatchRequest(ERXApplication.java:1986)
> 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(Unknown Source)
> "WorkerThread68":
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x00000007409438e0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
> at java.util.concurrent.locks.LockSupport.park(Unknown Source)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(Unknown Source)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Unknown Source)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(Unknown Source)
> at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(Unknown Source)
> at java.util.concurrent.locks.ReentrantLock.lock(Unknown Source)
> at com.webobjects.eocontrol.EOObjectStoreCoordinator.lock(EOObjectStoreCoordinator.java:420)
> at er.extensions.eof.ERXObjectStoreCoordinator.lock(ERXObjectStoreCoordinator.java:116)
> at com.webobjects.eocontrol.EOEditingContext.lockObjectStore(EOEditingContext.java:4666)
> at er.extensions.eof.ERXEC.lockObjectStore(ERXEC.java:724)
> at com.webobjects.eocontrol.EOCustomObject.willRead(EOCustomObject.java:1165)
> at com.webobjects.eocontrol._EOMutableKnownKeyDictionary$Initializer$_GenericRecordBinding.valueInObject(_EOMutableKnownKeyDictionary.java:570)
> at com.webobjects.eocontrol._EOMutableKnownKeyDictionary$Initializer$_LazyGenericRecordBinding.valueInObject(_EOMutableKnownKeyDictionary.java:613)
> at er.extensions.eof.ERXGenericRecord$TouchingBinding.valueInObject(ERXGenericRecord.java:205)
> at com.webobjects.eocontrol.EOCustomObject.storedValueForKey(EOCustomObject.java:1634)
> at com.theapp.security.model._EGMUser.eGMLocation(Unknown Source)
> at com.theapp.components.Header.tagline(Unknown Source)
> at sun.reflect.GeneratedMethodAccessor241.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
> at java.lang.reflect.Method.invoke(Unknown Source)
> at com.webobjects.foundation.NSKeyValueCoding$ValueAccessor$1.methodValue(NSKeyValueCoding.java:636)
> 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 er.extensions.components._private.ERXWOString.appendToResponse(ERXWOString.java:70)
> at com.webobjects.appserver._private.WODynamicGroup.appendChildrenToResponse(WODynamicGroup.java:126)
> at com.webobjects.appserver._private.WODynamicGroup.appendToResponse(WODynamicGroup.java:136)
> at com.webobjects.appserver.WOComponent.appendToResponse(WOComponent.java:1122)
> at er.extensions.components.ERXComponent.appendToResponse(ERXComponent.java:117)
> at com.webobjects.appserver._private.WOComponentReference.appendToResponse(WOComponentReference.java:135)
> at com.webobjects.appserver._private.WODynamicGroup.appendChildrenToResponse(WODynamicGroup.java:126)
> at com.webobjects.appserver._private.WOGenericContainer.appendToResponse(WOGenericContainer.java:44)
> at com.webobjects.appserver._private.WODynamicGroup.appendChildrenToResponse(WODynamicGroup.java:126)
> at com.webobjects.appserver._private.WODynamicGroup.appendToResponse(WODynamicGroup.java:136)
> at com.webobjects.appserver.WOComponent.appendToResponse(WOComponent.java:1122)
> at com.webobjects.appserver._private.WOComponentReference.appendToResponse(WOComponentReference.java:135)
> at com.webobjects.appserver._private.WODynamicGroup.appendChildrenToResponse(WODynamicGroup.java:126)
> at com.webobjects.appserver._private.WODynamicGroup.appendToResponse(WODynamicGroup.java:136)
> at com.webobjects.appserver.WOComponent.appendToResponse(WOComponent.java:1122)
> at er.extensions.components.ERXComponent.appendToResponse(ERXComponent.java:117)
> at com.webobjects.appserver.WOSession.appendToResponse(WOSession.java:1385)
> at er.extensions.appserver.ERXSession.appendToResponse(ERXSession.java:552)
> at com.webobjects.appserver.WOApplication.appendToResponse(WOApplication.java:1794)
> at er.extensions.appserver.ERXApplication.appendToResponse(ERXApplication.java:1923)
> at com.webobjects.appserver._private.WOComponentRequestHandler._dispatchWithPreparedPage(WOComponentRequestHandler.java:242)
> 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:445)
> at com.webobjects.appserver.WOApplication.dispatchRequest(WOApplication.java:1687)
> at er.extensions.appserver.ERXApplication.dispatchRequestImmediately(ERXApplication.java:2021)
> at er.extensions.appserver.ERXApplication.dispatchRequest(ERXApplication.java:1986)
> 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(Unknown Source)
>
>
>
>
> On Nov 28, 2012, at 6:47 PM, Chuck Hill wrote:
>
>> Now that is a good thought!
>>
>> On 2012-11-28, at 3:43 PM, Q wrote:
>>
>>> If you are doing concurrent dispatch then this might be worth doing even after they have been running for a while. It could be that you have a deadlock issue and are slowly deadlocking all your worker threads over time until eventually they all become non-responsive and the app instance is effectively dead in the water.
>>>
>>>
>>> On 29/11/2012, at 6:39 AM, Chuck Hill <email@hidden> wrote:
>>>
>>>> Try running jstack on them when the start not responding:
>>>>
>>>> jstack -F <process id>
>>>>
>>>> That will give you a thread dump and may show something.
>>>>
>>>> Have you looked in the logs for OutOfMemory and HeapSpace? It could be running out of PermGen space
>>>>
>>>> Are you dispatching requests concurrently?
>>>>
>>>>
>>>> Chuck
>>>>
>>>>
>>>> On 2012-11-28, at 12:05 PM, Michael Gargano wrote:
>>>>
>>>>> Hi all,
>>>>>
>>>>> I’m having an issue in our production environment. I have two servers (vm’s w/ windows 2008 r2 64-bit) running two instances each. The servers are load balanced by a hardware load balancer that pings the app on each box every minute to determine if it is still up (because of the way our app works, this creates a session). After about a week of uptime, the each app instance seems to just stop responding to requests one at a time until no instances respond any more. The java processes are still always running, but nothing responds. I recently bumped up the mem. on the apps to 3G each, to see if that would help, but the same problem occurred. Any ideas why this might be happening? It’s not good. Below is a sample of the app switches…
>>>>>
>>>>> -WOPort 2001 -WOCachingEnabled YES -WODebuggingEnabled NO -WOOutputPath c:/logs/log-1 -WOAutoOpenInBrowser NO -WOAutoOpenClientApplication NO -WOLifebeatInterval 120 -WOLifebeatEnabled YES -WOLifebeatDestinationPort 1085 -WOAdaptor WODefaultAdaptor -WOWorkerThreadCount 8 -WOListenQueueSize 128 -WOWorkerThreadCountMin 16 -WOWorkerThreadCountMax 256 -NSProjectSearchPath () -WOSessionTimeOut 1800 -WOApplicationName eGM -WOMonitorEnabled YES -WONoPause YES -Xmx3g -WOAllowsConcurrentRequestHandling YES
>>>>>
>>>>>
>>>>> Thanks.
>>>>> -Mike
>>>>>
>>>>> _______________________________________________
>>>>> 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
>>>>
>>>> --
>>>> Chuck Hill Senior Consultant / VP Development
>>>>
>>>> Practical WebObjects - for developers who want to increase their overall knowledge of WebObjects or who are trying to solve specific problems.
>>>> http://www.global-village.net/gvc/practical_webobjects
>>>>
>>>> Global Village Consulting ranks 13th in 2012 in BIV's Top 100 Fastest Growing Companies in B.C!
>>>> Global Village Consulting ranks 76th in 24th annual PROFIT 200 ranking of Canada’s Fastest-Growing Companies by PROFIT Magazine!
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> _______________________________________________
>>>> 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
>>>
>>
>> --
>> Chuck Hill Senior Consultant / VP Development
>>
>> Practical WebObjects - for developers who want to increase their overall knowledge of WebObjects or who are trying to solve specific problems.
>> http://www.global-village.net/gvc/practical_webobjects
>>
>> Global Village Consulting ranks 13th in 2012 in BIV's Top 100 Fastest Growing Companies in B.C!
>> Global Village Consulting ranks 76th in 24th annual PROFIT 200 ranking of Canada’s Fastest-Growing Companies by PROFIT Magazine!
>>
>>
>>
>>
>>
>>
>>
>>
>>
>
>
--
Chuck Hill Senior Consultant / VP Development
Practical WebObjects - for developers who want to increase their overall knowledge of WebObjects or who are trying to solve specific problems.
http://www.global-village.net/gvc/practical_webobjects
Global Village Consulting ranks 13th in 2012 in BIV's Top 100 Fastest Growing Companies in B.C!
Global Village Consulting ranks 76th in 24th annual PROFIT 200 ranking of Canada’s Fastest-Growing Companies by PROFIT Magazine!
_______________________________________________
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