Bug 62810 - Deadlock when closing editors and save
Summary: Deadlock when closing editors and save
Status: VERIFIED FIXED
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Core (show other bugs)
Version: 3.0   Edit
Hardware: PC Windows XP
: P2 normal (vote)
Target Milestone: 3.0 RC1   Edit
Assignee: Jerome Lanneluc CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2004-05-18 17:22 EDT by Martin Aeschlimann CLA
Modified: 2004-05-28 15:29 EDT (History)
0 users

See Also:


Attachments
More readable thread dump (16.98 KB, text/plain)
2004-05-19 04:50 EDT, Jerome Lanneluc CLA
no flags Details
Proposed patch (3.54 KB, patch)
2004-05-19 07:01 EDT, Jerome Lanneluc CLA
no flags Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Martin Aeschlimann CLA 2004-05-18 17:22:36 EDT
I20040518

- I used 'Close All' to close multiple editor where some of them were not saved.
When asked to saved, I saved them all

Not sure if I undertstood it correctly, but I think "Worker-90" has the
workpsace lock and waits for the Java model lock. "main" has it the other way around


Full thread dump Java HotSpot(TM) Client VM (1.4.2-b28 mixed mode):

"Worker-91" prio=5 tid=0x037a9010 nid=0xdd8 in Object.wait() [693f000..693fd94]
        at java.lang.Object.wait(Native Method)
        at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:209)
        - locked <0x12b5adb0> (a org.eclipse.core.internal.jobs.WorkerPool)
        at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:236)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:59)

"Worker-90" prio=5 tid=0x05e46710 nid=0x414 waiting for monitor entry
[686f000..686fd94]
        at
org.eclipse.jdt.internal.core.JavaModelManager.containerGet(JavaModelManager.java:160)
        - waiting to lock <0x12dd4360> (a
org.eclipse.jdt.internal.core.JavaModelManager)
        at
org.eclipse.jdt.internal.core.JavaModelManager.getClasspathContainer(JavaModelManager.java:817)
        at
org.eclipse.jdt.internal.core.ClasspathEntry.validateClasspathEntry(ClasspathEntry.java:1005)
        at
org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath(JavaProject.java:1849)
        at
org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath(JavaProject.java:1788)
        at
org.eclipse.jdt.internal.core.DeltaProcessor.updateClasspathMarkers(DeltaProcessor.java:2162)
        at
org.eclipse.jdt.internal.core.DeltaProcessor.updateClasspathMarkers(DeltaProcessor.java:2192)
        at
org.eclipse.jdt.internal.core.DeltaProcessor.updateClasspathMarkers(DeltaProcessor.java:2208)
        at
org.eclipse.jdt.internal.core.DeltaProcessor.resourceChanged(DeltaProcessor.java:1912)
        at
org.eclipse.jdt.internal.core.DeltaProcessingState.resourceChanged(DeltaProcessingState.java:414)
        at
org.eclipse.core.internal.events.NotificationManager$2.run(NotificationManager.java:313)
        at
org.eclipse.core.internal.runtime.InternalPlatform.run(InternalPlatform.java:608)
        at org.eclipse.core.runtime.Platform.run(Platform.java:750)
        at
org.eclipse.core.internal.events.NotificationManager.notify(NotificationManager.java:307)
        at
org.eclipse.core.internal.events.NotificationManager.broadcastChanges(NotificationManager.java:154)
        at
org.eclipse.core.internal.events.AutoBuildJob.broadcastChanges(AutoBuildJob.java:76)
        at
org.eclipse.core.internal.events.AutoBuildJob.doBuild(AutoBuildJob.java:149)
        at org.eclipse.core.internal.events.AutoBuildJob.run(AutoBuildJob.java:198)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:66)

"Worker-89" prio=5 tid=0x05dcad08 nid=0x820 in Object.wait() [68ff000..68ffd94]
        at java.lang.Object.wait(Native Method)
        at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:209)
        - locked <0x12b5adb0> (a org.eclipse.core.internal.jobs.WorkerPool)
        at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:236)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:59)

"Worker-88" prio=5 tid=0x0394e300 nid=0x1ac waiting on condition [67af000..67afd94]
        at java.lang.Thread.sleep(Native Method)
        at
org.eclipse.jdt.internal.core.search.processing.JobManager$1$ProgressJob.run(JobManager.java:321)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:66)

"Worker-83" prio=5 tid=0x03931278 nid=0xf98 in Object.wait() [67ef000..67efd94]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x103600b8> (a org.eclipse.core.internal.jobs.ThreadJob)
        at org.eclipse.core.internal.jobs.ThreadJob.joinRun(ThreadJob.java:159)
        - locked <0x103600b8> (a org.eclipse.core.internal.jobs.ThreadJob)
        at org.eclipse.core.internal.jobs.ImplicitJobs.begin(ImplicitJobs.java:87)
        at org.eclipse.core.internal.jobs.JobManager.beginRule(JobManager.java:167)
        at
org.eclipse.ui.internal.editors.quickdiff.LastSaveReferenceProvider.readDocument(LastSaveReferenceProvider.ja
va:225)
        at
org.eclipse.ui.internal.editors.quickdiff.LastSaveReferenceProvider.access$0(LastSaveReferenceProvider.java:1
91)
        at
org.eclipse.ui.internal.editors.quickdiff.LastSaveReferenceProvider$ReadJob.run(LastSaveReferenceProvider.jav
a:101)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:66)

"org.eclipse.jdt.internal.ui.text.JavaReconciler" daemon prio=2 tid=0x05e66e10
nid=0xea8 in Object.wait() [4b1f000..4b1f
d94]
        at java.lang.Object.wait(Native Method)
        at
org.eclipse.jface.text.reconciler.AbstractReconciler$BackgroundThread.run(AbstractReconciler.java:172)
        - locked <0x136df9f8> (a org.eclipse.jface.text.reconciler.DirtyRegionQueue)

"org.eclipse.jdt.internal.ui.text.JavaReconciler" daemon prio=2 tid=0x05d77e38
nid=0xe9c in Object.wait() [682f000..682f
d94]
        at java.lang.Object.wait(Native Method)
        at
org.eclipse.jface.text.reconciler.AbstractReconciler$BackgroundThread.run(AbstractReconciler.java:172)
        - locked <0x135771a8> (a org.eclipse.jface.text.reconciler.DirtyRegionQueue)

"org.eclipse.jdt.internal.ui.text.JavaReconciler" daemon prio=2 tid=0x038c2858
nid=0xc94 in Object.wait() [5a2f000..5a2f
d94]
        at java.lang.Object.wait(Native Method)
        at
org.eclipse.jface.text.reconciler.AbstractReconciler$BackgroundThread.run(AbstractReconciler.java:172)
        - locked <0x13519118> (a org.eclipse.jface.text.reconciler.DirtyRegionQueue)

"org.eclipse.jdt.internal.ui.text.JavaReconciler" daemon prio=2 tid=0x038c0598
nid=0xb40 in Object.wait() [579f000..579f
d94]
        at java.lang.Object.wait(Native Method)
        at
org.eclipse.jface.text.reconciler.AbstractReconciler$BackgroundThread.run(AbstractReconciler.java:172)
        - locked <0x134cb8e8> (a org.eclipse.jface.text.reconciler.DirtyRegionQueue)

"org.eclipse.jdt.internal.ui.text.JavaReconciler" daemon prio=2 tid=0x038bcf78
nid=0x95c in Object.wait() [522f000..522f
d94]
        at java.lang.Object.wait(Native Method)
        at
org.eclipse.jface.text.reconciler.AbstractReconciler$BackgroundThread.run(AbstractReconciler.java:172)
        - locked <0x134845e8> (a org.eclipse.jface.text.reconciler.DirtyRegionQueue)

"Java indexing" daemon prio=4 tid=0x03472bb0 nid=0xaa0 in Object.wait()
[599f000..599fd94]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x101e2bd0> (a org.eclipse.core.internal.jobs.Semaphore)
        at org.eclipse.core.internal.jobs.Semaphore.acquire(Semaphore.java:38)
        - locked <0x101e2bd0> (a org.eclipse.core.internal.jobs.Semaphore)
        at
org.eclipse.core.internal.jobs.OrderedLock.doAcquire(OrderedLock.java:171)
        at org.eclipse.core.internal.jobs.OrderedLock.acquire(OrderedLock.java:105)
        at org.eclipse.core.internal.jobs.OrderedLock.acquire(OrderedLock.java:79)
        at
org.eclipse.core.internal.resources.WorkManager.checkIn(WorkManager.java:96)
        at
org.eclipse.core.internal.resources.Workspace.prepareOperation(Workspace.java:1632)
        at
org.eclipse.core.internal.resources.File.getContentDescription(File.java:254)
        at org.eclipse.core.internal.resources.File.getCharset(File.java:220)
        at org.eclipse.core.internal.resources.File.getCharset(File.java:205)
        at
org.eclipse.jdt.internal.core.search.JavaSearchDocument.getEncoding(JavaSearchDocument.java:71)
        at
org.eclipse.jdt.internal.core.search.JavaSearchDocument.getCharContents(JavaSearchDocument.java:58)
        at
org.eclipse.jdt.internal.core.search.indexing.SourceIndexer.indexDocument(SourceIndexer.java:67)
        at
org.eclipse.jdt.internal.core.search.JavaSearchParticipant.indexDocument(JavaSearchParticipant.java:72)
        at
org.eclipse.jdt.internal.core.search.indexing.IndexManager.indexDocument(IndexManager.java:258)
        at
org.eclipse.jdt.internal.core.search.indexing.IndexManager$1.execute(IndexManager.java:566)
        at
org.eclipse.jdt.internal.core.search.processing.JobManager.run(JobManager.java:367)
        at java.lang.Thread.run(Thread.java:534)

"Thread-1" prio=7 tid=0x00a29b70 nid=0x1f0 in Object.wait() [3bff000..3bffd94]
        at java.lang.Object.wait(Native Method)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
        - locked <0x12b9f6a8> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
        at
org.eclipse.jface.action.ActionContributionItem$ImageCache$ReferenceCleanerThread.run(ActionContributionItem.
java:196)

"Thread-0" prio=7 tid=0x0345fcf0 nid=0xe3c in Object.wait() [3bbf000..3bbfd94]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x12b9f718> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
        - locked <0x12b9f718> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
        at
org.eclipse.jface.action.ActionContributionItem$ImageCache$ReferenceCleanerThread.run(ActionContributionItem.
java:196)

"Start Level Event Dispatcher" daemon prio=5 tid=0x00a488b0 nid=0x4bc in
Object.wait() [355f000..355fd94]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x12770060> (a
org.eclipse.osgi.framework.eventmgr.EventThread)
        at java.lang.Object.wait(Object.java:429)
        at
org.eclipse.osgi.framework.eventmgr.EventThread.getNextEvent(EventThread.java:162)
        - locked <0x12770060> (a org.eclipse.osgi.framework.eventmgr.EventThread)
        at org.eclipse.osgi.framework.eventmgr.EventThread.run(EventThread.java:100)

"Framework Event Dispatcher" daemon prio=5 tid=0x00a5aaf8 nid=0x8c0 in
Object.wait() [351f000..351fd94]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x12770220> (a
org.eclipse.osgi.framework.eventmgr.EventThread)
        at java.lang.Object.wait(Object.java:429)
        at
org.eclipse.osgi.framework.eventmgr.EventThread.getNextEvent(EventThread.java:162)
        - locked <0x12770220> (a org.eclipse.osgi.framework.eventmgr.EventThread)
        at org.eclipse.osgi.framework.eventmgr.EventThread.run(EventThread.java:100)

"Signal Dispatcher" daemon prio=10 tid=0x0003f648 nid=0x900 waiting on condition
[0..0]

"Finalizer" daemon prio=9 tid=0x009c0798 nid=0xa14 in Object.wait()
[2d0f000..2d0fd94]
        at java.lang.Object.wait(Native Method)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
        - locked <0x127704f0> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x009bf368 nid=0xe98 in Object.wait()
[2ccf000..2ccfd94]
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:429)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:115)
        - locked <0x127700b0> (a java.lang.ref.Reference$Lock)

"main" prio=7 tid=0x00035a18 nid=0xa7c in Object.wait() [7e000..7fc3c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x101a3058> (a org.eclipse.core.internal.jobs.Semaphore)
        at org.eclipse.core.internal.jobs.Semaphore.acquire(Semaphore.java:38)
        - locked <0x101a3058> (a org.eclipse.core.internal.jobs.Semaphore)
        at
org.eclipse.core.internal.jobs.OrderedLock.doAcquire(OrderedLock.java:171)
        at org.eclipse.core.internal.jobs.OrderedLock.acquire(OrderedLock.java:105)
        at org.eclipse.core.internal.jobs.OrderedLock.acquire(OrderedLock.java:79)
        at
org.eclipse.core.internal.resources.WorkManager.checkIn(WorkManager.java:96)
        at
org.eclipse.core.internal.resources.Workspace.prepareOperation(Workspace.java:1632)
        at
org.eclipse.core.internal.resources.File.getContentDescription(File.java:254)
        at org.eclipse.core.internal.resources.File.getCharset(File.java:220)
        at org.eclipse.core.internal.resources.File.getCharset(File.java:205)
        at
org.eclipse.jdt.internal.core.util.Util.getResourceContentsAsCharArray(Util.java:828)
        at
org.eclipse.jdt.internal.core.CompilationUnit.openBuffer(CompilationUnit.java:1028)
        at
org.eclipse.jdt.internal.core.CompilationUnit.buildStructure(CompilationUnit.java:102)
        at org.eclipse.jdt.internal.core.Openable.generateInfos(Openable.java:183)
        at
org.eclipse.jdt.internal.core.JavaElement.openWhenClosed(JavaElement.java:573)
        at
org.eclipse.jdt.internal.core.JavaElement.getElementInfo(JavaElement.java:310)
        at
org.eclipse.jdt.internal.core.JavaElement.getElementInfo(JavaElement.java:296)
        at
org.eclipse.jdt.internal.core.JavaElementDeltaBuilder.recordNewPositions(JavaElementDeltaBuilder.java:351)
        at
org.eclipse.jdt.internal.core.JavaElementDeltaBuilder.buildDeltas(JavaElementDeltaBuilder.java:135)
        at
org.eclipse.jdt.internal.core.JavaModelManager.discardPerWorkingCopyInfo(JavaModelManager.java:775)
        - locked <0x12dd5890> (a java.util.HashMap)
        - locked <0x12dd4360> (a org.eclipse.jdt.internal.core.JavaModelManager)
        at
org.eclipse.jdt.internal.core.DiscardWorkingCopyOperation.executeOperation(DiscardWorkingCopyOperation.java:2
9)
        at
org.eclipse.jdt.internal.core.JavaModelOperation.run(JavaModelOperation.java:700)
        at
org.eclipse.jdt.internal.core.JavaModelOperation.runOperation(JavaModelOperation.java:739)
        at
org.eclipse.jdt.internal.core.CompilationUnit.discardWorkingCopy(CompilationUnit.java:413)
        at
org.eclipse.jdt.internal.ui.javaeditor.CompilationUnitDocumentProvider.disposeFileInfo(CompilationUnitDocumen
tProvider.java:857)
        at
org.eclipse.ui.editors.text.TextFileDocumentProvider.disconnect(TextFileDocumentProvider.java:510)
        at
org.eclipse.ui.texteditor.AbstractTextEditor.disposeDocumentProvider(AbstractTextEditor.java:2931)
        at
org.eclipse.ui.texteditor.AbstractDecoratedTextEditor.disposeDocumentProvider(AbstractDecoratedTextEditor.jav
a:1055)
        at
org.eclipse.ui.texteditor.AbstractTextEditor.dispose(AbstractTextEditor.java:2854)
        at
org.eclipse.ui.texteditor.AbstractDecoratedTextEditor.dispose(AbstractDecoratedTextEditor.java:215)
        at
org.eclipse.jdt.internal.ui.javaeditor.JavaEditor.dispose(JavaEditor.java:2836)
        at
org.eclipse.jdt.internal.ui.javaeditor.CompilationUnitEditor.dispose(CompilationUnitEditor.java:1588)
        at
org.eclipse.ui.internal.WorkbenchPartReference.dispose(WorkbenchPartReference.java:179)
        at
org.eclipse.ui.internal.EditorManager$Editor.dispose(EditorManager.java:1195)
        at org.eclipse.ui.internal.WorkbenchPage$5.run(WorkbenchPage.java:1170)
        at
org.eclipse.core.internal.runtime.InternalPlatform.run(InternalPlatform.java:608)
        at org.eclipse.core.runtime.Platform.run(Platform.java:750)
        at
org.eclipse.ui.internal.WorkbenchPage.disposePart(WorkbenchPage.java:1168)
        at
org.eclipse.ui.internal.WorkbenchPage.closeEditors(WorkbenchPage.java:909)
        at
org.eclipse.ui.internal.WorkbenchPage.closeAllEditors(WorkbenchPage.java:853)
        at org.eclipse.ui.internal.CloseAllAction.run(CloseAllAction.java:74)
        at org.eclipse.jface.action.Action.runWithEvent(Action.java:881)
        at
org.eclipse.jface.action.ActionContributionItem.handleWidgetSelection(ActionContributionItem.java:899)
        at
org.eclipse.jface.action.ActionContributionItem.access$2(ActionContributionItem.java:850)
        at
org.eclipse.jface.action.ActionContributionItem$7.handleEvent(ActionContributionItem.java:769)
        at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:82)
        at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:796)
        at org.eclipse.swt.widgets.Display.runDeferredEvents(Display.java:2716)
        at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:2382)
        at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:1363)
        at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:1334)
        at
org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:253)
        at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:141)
        at org.eclipse.ui.internal.ide.IDEApplication.run(IDEApplication.java:97)
        at
org.eclipse.core.internal.runtime.PlatformActivator$1.run(PlatformActivator.java:299)
        at
org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:256)
        at
org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:127)
        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:324)
        at org.eclipse.core.launcher.Main.basicRun(Main.java:184)
        at org.eclipse.core.launcher.Main.run(Main.java:637)
        at org.eclipse.core.launcher.Main.main(Main.java:621)

"VM Thread" prio=5 tid=0x009fb6c0 nid=0x194 runnable

"VM Periodic Task Thread" prio=10 tid=0x009fd190 nid=0xe4c waiting on condition
"Suspend Checker Thread" prio=10 tid=0x0003d0b8 nid=0xe48 runnable
Comment 1 Philipe Mulet CLA 2004-05-18 17:54:39 EDT
You read the lock correctly. Offending code is:

org.eclipse.jdt.internal.core.JavaModelManager.discardPerWorkingCopyInfo
(JavaModelManager.java:775)
        - locked <0x12dd5890> (a java.util.HashMap)
        - locked <0x12dd4360> (a 
org.eclipse.jdt.internal.core.JavaModelManager)

It should not get the lock on the JavaModelManager for the entire duration of 
the process, since proven to induce some resource operation indirectly.

I find the double locking very suspicious...

/*
 * Discards the per working copy info for the given working copy (making it a 
compilation unit)
 * if its use count was 1. Otherwise, just decrement the use count.
 * If the working copy is primary, computes the delta between its state and 
the original compilation unit
 * and register it.
 * Close the working copy, its buffer and remove it from the shared working 
copy table.
 * Ignore if no per-working copy info existed.
 * NOTE: it must be synchronized as it may interact with the element info 
cache (if useCount is decremented to 0), see bug 50667.
 * Returns the new use count (or -1 if it didn't exist).
 */
public synchronized int discardPerWorkingCopyInfo(CompilationUnit workingCopy) 
throws JavaModelException {
  synchronized(perWorkingCopyInfos)


		
Comment 2 Jerome Lanneluc CLA 2004-05-19 04:42:08 EDT
Martin, I don't see the workspace lock being taken in "Worker-90". What lead 
you to this assumption?
Comment 3 Jerome Lanneluc CLA 2004-05-19 04:50:05 EDT
Created attachment 10817 [details]
More readable thread dump
Comment 4 Jerome Lanneluc CLA 2004-05-19 05:50:25 EDT
Ok, there is no real workspace lock, but the "main" thread is waiting 
for "Worker-90" to complete. Problem is that "main" has the JavaModelManager 
lock and "Worker-90" is waiting for this lock.
Comment 5 Jerome Lanneluc CLA 2004-05-19 07:01:49 EDT
Created attachment 10819 [details]
Proposed patch

This change is little bit risky for M9, and should be heavily tested before
releasing it. Will wait for RC1.
Comment 6 Jerome Lanneluc CLA 2004-05-24 11:04:11 EDT
Patch released. It consists in removing the synchronized modifier on the 
JavaModelManager#discardPerWorkingCopyInfo(CompilationUnit) method (this fixes 
this bug) and moving all Java element info access outside (so that we don't 
reintroduce bug 50667).
Comment 7 Olivier Thomann CLA 2004-05-28 15:29:23 EDT
Could not reproduce anymore.
Verified in 200405281200