Bug 248676 - Deadlock in ModelManagerImpl._commonGetModel(..)
Summary: Deadlock in ModelManagerImpl._commonGetModel(..)
Status: RESOLVED WORKSFORME
Alias: None
Product: WTP Source Editing
Classification: WebTools
Component: wst.sse (show other bugs)
Version: 3.0.1   Edit
Hardware: PC Windows XP
: P3 normal (vote)
Target Milestone: ---   Edit
Assignee: wst.sse CLA
QA Contact: Nitin Dahyabhai CLA
URL:
Whiteboard:
Keywords: needinfo
Depends on:
Blocks:
 
Reported: 2008-09-25 22:11 EDT by Randall Theobald CLA
Modified: 2010-04-28 17:41 EDT (History)
3 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Randall Theobald CLA 2008-09-25 22:11:49 EDT
Build ID: 3.4.0.v20080604-1400

Steps To Reproduce:
See description of problem below.

More information:
I am a performance analyst for an adopting product. I ran into a deadlock (CPU idle) during one of my many automated runs (a build of the workspace) that I haven't run into before. While it might be nigh impossible to reproduce, I thought I'd document it.

A javacore dump showed that the build thread was stuck:

*******************************************************

"Worker-4" TID:0x18FC4200, j9thread_t:0x1F6596F0, state:CW, prio=2
       (native thread ID:0xE7C, native priority:0x2, native policy:UNKNOWN)
    at java/lang/Object.wait(Native Method)
    at java/lang/Object.wait(Object.java:167)
    at org/eclipse/wst/sse/core/internal/model/ModelManagerImpl$SharedObject.waitForLoadAttempt(ModelManagerImpl.java:127)
    at org/eclipse/wst/sse/core/internal/model/ModelManagerImpl._commonGetModel(ModelManagerImpl.java:433)
    at org/eclipse/wst/sse/core/internal/model/ModelManagerImpl._commonGetModel(ModelManagerImpl.java:416)
    at org/eclipse/wst/sse/core/internal/model/ModelManagerImpl.getModelForEdit(ModelManagerImpl.java:1276)
    at org/eclipse/wst/xml/core/internal/emf2xml/EMF2DOMSSERenderer.initializeXMLModel(EMF2DOMSSERenderer.java:360)
    at org/eclipse/wst/xml/core/internal/emf2xml/EMF2DOMSSERenderer.createDocument(EMF2DOMSSERenderer.java:183)
    at org/eclipse/wst/common/internal/emf/resource/EMF2DOMRenderer.createDOMTree(EMF2DOMRenderer.java:127)
    at org/eclipse/wst/xml/core/internal/emf2xml/EMF2DOMSSERenderer.createDOMTreeIfNecessary(EMF2DOMSSERenderer.java:192)
    at org/eclipse/wst/xml/core/internal/emf2xml/EMF2DOMSSERenderer.doSave(EMF2DOMSSERenderer.java:249)
    at org/eclipse/wst/common/internal/emf/resource/TranslatorResourceImpl.doSave(TranslatorResourceImpl.java:180)
    at org/eclipse/wst/common/internal/emf/resource/TranslatorResourceImpl.save(TranslatorResourceImpl.java:160)
    at org/eclipse/wst/common/internal/emf/resource/ReferencedXMIResourceImpl.saveIfNecessary(ReferencedXMIResourceImpl.java:272)
    at org/eclipse/jst/j2ee/ejb/componentcore/util/EJBArtifactEdit.addEJBJarIfNecessary(EJBArtifactEdit.java:372)
    at org/eclipse/jst/j2ee/ejb/componentcore/util/EJBArtifactEdit.getDeploymentDescriptorRoot(EJBArtifactEdit.java:325)
    at org/eclipse/jst/j2ee/ejb/componentcore/util/EJBArtifactEdit.getEJBJar(EJBArtifactEdit.java:301)
	<product code>
    at org/eclipse/core/internal/resources/Workspace.run(Workspace.java:1800)
    at org/eclipse/core/internal/resources/Workspace.run(Workspace.java:1782)
	<product code>
    at org/eclipse/core/internal/events/BuildManager$2.run(BuildManager.java:633)
    at org/eclipse/core/runtime/SafeRunner.run(SafeRunner.java:37(Compiled Code))
    at org/eclipse/core/internal/events/BuildManager.basicBuild(BuildManager.java:170)
    at org/eclipse/core/internal/events/BuildManager.basicBuild(BuildManager.java:201)
    at org/eclipse/core/internal/events/BuildManager$1.run(BuildManager.java:253)
    at org/eclipse/core/runtime/SafeRunner.run(SafeRunner.java:37(Compiled Code))
    at org/eclipse/core/internal/events/BuildManager.basicBuild(BuildManager.java:256)
    at org/eclipse/core/internal/events/BuildManager.basicBuildLoop(BuildManager.java:309)
    at org/eclipse/core/internal/events/BuildManager.build(BuildManager.java:341)
    at org/eclipse/core/internal/resources/Workspace.build(Workspace.java:330)
    at org/eclipse/ui/actions/GlobalBuildAction$1.run(GlobalBuildAction.java:182)
    at org/eclipse/core/internal/jobs/Worker.run(Worker.java:55(Compiled Code))

*******************************************************

The .log file showed a highly suspect entry. A ResourceException that occurred exactly when the CPU went idle (according to my perf logs):

*********************************************************

!ENTRY org.eclipse.wst.xml.core 4 4 2008-09-25 19:02:58.046
!MESSAGE Resource '/DMPackingSlipServiceEJB/ejbModule/META-INF/ejb-jar.xml' already exists.
!STACK 1
org.eclipse.core.internal.resources.ResourceException: Resource '/DMPackingSlipServiceEJB/ejbModule/META-INF/ejb-jar.xml' already exists.
	at org.eclipse.core.internal.resources.Resource.checkDoesNotExist(Resource.java:296)
	at org.eclipse.core.internal.resources.Resource.checkDoesNotExist(Resource.java:283)
	at org.eclipse.core.internal.resources.File.create(File.java:116)
	at org.eclipse.core.internal.resources.File.create(File.java:186)
	at org.eclipse.wst.xml.core.internal.emf2xml.EMF2DOMSSERenderer.createDocument(EMF2DOMSSERenderer.java:172)
	at org.eclipse.wst.common.internal.emf.resource.EMF2DOMRenderer.createDOMTree(EMF2DOMRenderer.java:127)
	at org.eclipse.wst.xml.core.internal.emf2xml.EMF2DOMSSERenderer.createDOMTreeIfNecessary(EMF2DOMSSERenderer.java:192)
	at org.eclipse.wst.xml.core.internal.emf2xml.EMF2DOMSSERenderer.doSave(EMF2DOMSSERenderer.java:249)
	at org.eclipse.wst.common.internal.emf.resource.TranslatorResourceImpl.doSave(TranslatorResourceImpl.java:180)
	at org.eclipse.wst.common.internal.emf.resource.TranslatorResourceImpl.save(TranslatorResourceImpl.java:160)
	at org.eclipse.wst.common.internal.emf.resource.ReferencedXMIResourceImpl.saveIfNecessary(ReferencedXMIResourceImpl.java:272)
	at org.eclipse.jst.j2ee.ejb.componentcore.util.EJBArtifactEdit.addEJBJarIfNecessary(EJBArtifactEdit.java:372)
	at org.eclipse.jst.j2ee.ejb.componentcore.util.EJBArtifactEdit.getDeploymentDescriptorRoot(EJBArtifactEdit.java:325)
	at org.eclipse.jst.j2ee.ejb.componentcore.util.EJBArtifactEdit.getEJBJar(EJBArtifactEdit.java:301)
  <product code>	
	at org.eclipse.core.internal.resources.Workspace.run(Workspace.java:1800)
	at org.eclipse.core.internal.resources.Workspace.run(Workspace.java:1782)
  <product code>	
	at org.eclipse.core.internal.events.BuildManager$2.run(BuildManager.java:633)
	at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:37)
	at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:170)
	at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:201)
	at org.eclipse.core.internal.events.BuildManager$1.run(BuildManager.java:253)
	at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:37)
	at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:256)
	at org.eclipse.core.internal.events.BuildManager.basicBuildLoop(BuildManager.java:309)
	at org.eclipse.core.internal.events.BuildManager.build(BuildManager.java:341)
	at org.eclipse.core.internal.resources.Workspace.build(Workspace.java:330)
	at org.eclipse.ui.actions.GlobalBuildAction$1.run(GlobalBuildAction.java:182)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)
!SUBENTRY 1 org.eclipse.core.resources 4 374 2008-09-25 19:02:58.046
!MESSAGE Resource '/DMPackingSlipServiceEJB/ejbModule/META-INF/ejb-jar.xml' already exists.


*********************************************************

I tried looking through the code a bunch, but I can't figure out why on this rare occasion that it tried to create a document that was already there. Why wouldn't it always fail?

The deadlocking code is just shortly after the ResourceException was thrown, so that obviously put something into a weird state.
Comment 1 Nitin Dahyabhai CLA 2008-09-26 03:26:53 EDT
Are these the only threads running?  It's not obvious what is blocking your second trace, if anything.
Comment 2 Randall Theobald CLA 2009-01-13 14:04:41 EST
I only gave the callstack for one thread. The second callstack is from the .log file (not the javacore dump). I only included one thread because the javacore dump didn't show anything else that could have caused this thread to block. It simply waited on an object that never notified.

I have never seen this deadlock again, so it is obviously very difficult to reproduce. However, please take a quick look at the code involved and see if anything jumps out as possibly causing this problem. Otherwise, this bug can probably be closed as not reproducible.
Comment 3 Ian Tewksbury CLA 2010-02-17 11:23:55 EST
(In reply to comment #2)
> I have never seen this deadlock again, so it is obviously very difficult to
> reproduce. However, please take a quick look at the code involved and see if
> anything jumps out as possibly causing this problem. Otherwise, this bug can
> probably be closed as not reproducible.

Vote to resolve, if it is ever seen again maybe we can get some more information on it.
Comment 4 Nick Sandonato CLA 2010-04-28 17:41:56 EDT
Thanks for the details you've provided. A ton of work has gone into the model manager to reduce the likelihood of deadlock. Not an easily reproducible report.