Bug 175531 - Livelock in OverflowingLRUCache.privateRemoveEntry
Summary: Livelock in OverflowingLRUCache.privateRemoveEntry
Status: VERIFIED FIXED
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Core (show other bugs)
Version: 3.3   Edit
Hardware: PC Windows XP
: P3 major (vote)
Target Milestone: 3.3 M6   Edit
Assignee: Jerome Lanneluc CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2007-02-26 10:17 EST by Markus Keller CLA
Modified: 2022-01-13 10:57 EST (History)
1 user (show)

See Also:


Attachments
YourKit CPU trace (165.61 KB, text/html)
2007-02-26 10:18 EST, Markus Keller CLA
no flags Details
Proposed fix (4.14 KB, patch)
2007-02-27 11:42 EST, 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 Markus Keller CLA 2007-02-26 10:17:34 EST
I20070220-1330, ZRH-plugins and jdt.core from HEAD (20070226_0933)

I opened a .java file and wanted to start editing, but I was trapped in a livelock (1 CPU monopolized). I took a Yourkit trace and found that all time was burned in  org.eclipse.jdt.internal.core.OverflowingLRUCache.privateRemoveEntry(LRUCache$LRUCacheEntry, boolean, boolean)

Looks similar to bug 128000.
Comment 1 Markus Keller CLA 2007-02-26 10:18:12 EST
Created attachment 59790 [details]
YourKit CPU trace
Comment 2 Markus Keller CLA 2007-02-26 10:19:09 EST
2007-02-26 16:04:08
Full thread dump Java HotSpot(TM) Client VM (1.6.0_01-b04 mixed mode):

"org.eclipse.jdt.internal.ui.text.JavaReconciler" daemon prio=2 tid=0x06a0e400 nid=0x3ae8 waiting for monitor entry [0x0834e000..0x0834fa94]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.eclipse.jdt.internal.core.CompilationUnit.openBuffer(CompilationUnit.java:1055)
        - waiting to lock <0x1266f6d8> (a org.eclipse.jdt.internal.core.BufferManager)
        at org.eclipse.jdt.internal.core.CompilationUnit.buildStructure(CompilationUnit.java:89)
        at org.eclipse.jdt.internal.core.Openable.generateInfos(Openable.java:229)
        at org.eclipse.jdt.internal.core.SourceRefElement.generateInfos(SourceRefElement.java:107)
        at org.eclipse.jdt.internal.core.JavaElement.openWhenClosed(JavaElement.java:505)
        at org.eclipse.jdt.internal.core.JavaElement.getElementInfo(JavaElement.java:249)
        at org.eclipse.jdt.internal.core.JavaElement.getElementInfo(JavaElement.java:235)
        at org.eclipse.jdt.internal.core.SearchableEnvironment.find(SearchableEnvironment.java:113)
        at org.eclipse.jdt.internal.core.SearchableEnvironment.findType(SearchableEnvironment.java:282)
        at org.eclipse.jdt.internal.core.CancelableNameEnvironment.findType(CancelableNameEnvironment.java:45)
        at org.eclipse.jdt.internal.compiler.lookup.LookupEnvironment.askForType(LookupEnvironment.java:122)
        at org.eclipse.jdt.internal.compiler.lookup.PackageBinding.getTypeOrPackage(PackageBinding.java:178)
        at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.findImport(CompilationUnitScope.java:447)
        at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.findSingleImport(CompilationUnitScope.java:501)
        at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.faultInImports(CompilationUnitScope.java:357)
        at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.faultInTypes(CompilationUnitScope.java:426)
        at org.eclipse.jdt.internal.compiler.Compiler.resolve(Compiler.java:708)
        at org.eclipse.jdt.internal.compiler.Compiler.resolve(Compiler.java:755)
        at org.eclipse.jdt.internal.core.CompilationUnitProblemFinder.process(CompilationUnitProblemFinder.java:177)
        at org.eclipse.jdt.internal.core.CompilationUnitProblemFinder.process(CompilationUnitProblemFinder.java:249)
        at org.eclipse.jdt.internal.core.ReconcileWorkingCopyOperation.makeConsistent(ReconcileWorkingCopyOperation.java:166)
        at org.eclipse.jdt.internal.core.ReconcileWorkingCopyOperation.executeOperation(ReconcileWorkingCopyOperation.java:85)
        at org.eclipse.jdt.internal.core.JavaModelOperation.run(JavaModelOperation.java:720)
        at org.eclipse.jdt.internal.core.JavaModelOperation.runOperation(JavaModelOperation.java:779)
        at org.eclipse.jdt.internal.core.CompilationUnit.reconcile(CompilationUnit.java:1151)
        at org.eclipse.jdt.internal.ui.text.java.JavaReconcilingStrategy$1.run(JavaReconcilingStrategy.java:97)
        at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:37)
        at org.eclipse.jdt.internal.ui.text.java.JavaReconcilingStrategy.reconcile(JavaReconcilingStrategy.java:82)
        at org.eclipse.jdt.internal.ui.text.java.JavaReconcilingStrategy.initialReconcile(JavaReconcilingStrategy.java:172)
        at org.eclipse.jdt.internal.ui.text.CompositeReconcilingStrategy.initialReconcile(CompositeReconcilingStrategy.java:114)
        at org.eclipse.jdt.internal.ui.text.JavaCompositeReconcilingStrategy.initialReconcile(JavaCompositeReconcilingStrategy.java:122)
        at org.eclipse.jface.text.reconciler.MonoReconciler.initialProcess(MonoReconciler.java:103)
        at org.eclipse.jdt.internal.ui.text.JavaReconciler.initialProcess(JavaReconciler.java:332)
        - locked <0x10fa35e8> (a java.lang.Object)
        at org.eclipse.jface.text.reconciler.AbstractReconciler$BackgroundThread.run(AbstractReconciler.java:170)

"Worker-62" prio=6 tid=0x06a93800 nid=0x5f64 in Object.wait() [0x06f2f000..0x06f2fa94]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:186)
        - locked <0x119d0e98> (a org.eclipse.core.internal.jobs.WorkerPool)
        at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:218)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:51)

"Worker-61" prio=6 tid=0x0681b800 nid=0x79e4 runnable [0x07a8e000..0x07a8fb14]
   java.lang.Thread.State: RUNNABLE
        at org.eclipse.jdt.internal.core.OverflowingLRUCache.privateRemoveEntry(OverflowingLRUCache.java:281)
        at org.eclipse.jdt.internal.core.OverflowingLRUCache.makeSpace(OverflowingLRUCache.java:180)
        at org.eclipse.jdt.internal.core.OverflowingLRUCache.put(OverflowingLRUCache.java:345)
        at org.eclipse.jdt.internal.core.BufferManager.addBuffer(BufferManager.java:57)
        at org.eclipse.jdt.internal.core.CompilationUnit.openBuffer(CompilationUnit.java:1085)
        - locked <0x1266f6d8> (a org.eclipse.jdt.internal.core.BufferManager)
        at org.eclipse.jdt.internal.core.CompilationUnit.buildStructure(CompilationUnit.java:89)
        at org.eclipse.jdt.internal.core.Openable.generateInfos(Openable.java:229)
        at org.eclipse.jdt.internal.core.SourceRefElement.generateInfos(SourceRefElement.java:107)
        at org.eclipse.jdt.internal.core.JavaElement.openWhenClosed(JavaElement.java:505)
        at org.eclipse.jdt.internal.core.JavaElement.getElementInfo(JavaElement.java:249)
        at org.eclipse.jdt.internal.core.JavaElement.getElementInfo(JavaElement.java:235)
        at org.eclipse.jdt.internal.core.SearchableEnvironment.find(SearchableEnvironment.java:113)
        at org.eclipse.jdt.internal.core.SearchableEnvironment.findType(SearchableEnvironment.java:282)
        at org.eclipse.jdt.internal.compiler.lookup.LookupEnvironment.askForType(LookupEnvironment.java:122)
        at org.eclipse.jdt.internal.compiler.lookup.PackageBinding.getTypeOrPackage(PackageBinding.java:178)
        at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.findImport(CompilationUnitScope.java:447)
        at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.findSingleImport(CompilationUnitScope.java:501)
        at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.faultInImports(CompilationUnitScope.java:357)
        at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.faultInTypes(CompilationUnitScope.java:426)
        at org.eclipse.jdt.internal.core.hierarchy.HierarchyResolver.resolve(HierarchyResolver.java:733)
        at org.eclipse.jdt.internal.core.hierarchy.HierarchyResolver.resolve(HierarchyResolver.java:550)
        at org.eclipse.jdt.internal.core.hierarchy.HierarchyBuilder.buildSupertypes(HierarchyBuilder.java:115)
        at org.eclipse.jdt.internal.core.hierarchy.IndexBasedHierarchyBuilder.build(IndexBasedHierarchyBuilder.java:134)
        at org.eclipse.jdt.internal.core.hierarchy.TypeHierarchy.compute(TypeHierarchy.java:300)
        at org.eclipse.jdt.internal.core.hierarchy.TypeHierarchy.refresh(TypeHierarchy.java:1237)
        - locked <0x10fa4e98> (a org.eclipse.jdt.internal.core.hierarchy.TypeHierarchy)
        at org.eclipse.jdt.internal.core.CreateTypeHierarchyOperation.executeOperation(CreateTypeHierarchyOperation.java:90)
        at org.eclipse.jdt.internal.core.JavaModelOperation.run(JavaModelOperation.java:720)
        at org.eclipse.jdt.internal.core.JavaModelOperation.runOperation(JavaModelOperation.java:779)
        at org.eclipse.jdt.internal.core.SourceType.newSupertypeHierarchy(SourceType.java:697)
        at org.eclipse.jdt.internal.core.SourceType.newSupertypeHierarchy(SourceType.java:649)
        at org.eclipse.jdt.internal.corext.util.SuperTypeHierarchyCache.getTypeHierarchy(SuperTypeHierarchyCache.java:120)
        at org.eclipse.jdt.internal.corext.util.SuperTypeHierarchyCache.getTypeHierarchy(SuperTypeHierarchyCache.java:80)
        at org.eclipse.jdt.internal.corext.util.SuperTypeHierarchyCache.getMethodOverrideTester(SuperTypeHierarchyCache.java:89)
        at org.eclipse.jdt.ui.OverrideIndicatorLabelDecorator.getOverrideIndicators(OverrideIndicatorLabelDecorator.java:162)
        at org.eclipse.jdt.ui.OverrideIndicatorLabelDecorator.computeAdornmentFlags(OverrideIndicatorLabelDecorator.java:129)
        at org.eclipse.jdt.ui.OverrideIndicatorLabelDecorator.decorate(OverrideIndicatorLabelDecorator.java:261)
        at org.eclipse.ui.internal.decorators.LightweightDecoratorDefinition.decorate(LightweightDecoratorDefinition.java:259)
        at org.eclipse.ui.internal.decorators.LightweightDecoratorManager$LightweightRunnable.run(LightweightDecoratorManager.java:71)
        at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:37)
        at org.eclipse.core.runtime.Platform.run(Platform.java:850)
        at org.eclipse.ui.internal.decorators.LightweightDecoratorManager.decorate(LightweightDecoratorManager.java:336)
        at org.eclipse.ui.internal.decorators.LightweightDecoratorManager.getDecorations(LightweightDecoratorManager.java:322)
        at org.eclipse.ui.internal.decorators.DecorationScheduler$1.ensureResultCached(DecorationScheduler.java:357)
        at org.eclipse.ui.internal.decorators.DecorationScheduler$1.run(DecorationScheduler.java:322)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:58)

"Worker-59" prio=6 tid=0x06af8400 nid=0x3714 in Object.wait() [0x079df000..0x079dfb94]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:485)
        at org.eclipse.jdt.internal.ui.javaeditor.ASTProvider.getAST(ASTProvider.java:490)
        - locked <0x12587358> (a java.lang.Object)
        at org.eclipse.jdt.internal.ui.viewsupport.SelectionListenerWithASTManager$PartListenerGroup.calculateASTandInform(SelectionListenerWithASTMan
ager.java:155)
        at org.eclipse.jdt.internal.ui.viewsupport.SelectionListenerWithASTManager$3.run(SelectionListenerWithASTManager.java:140)
        - locked <0x10fa5020> (a java.lang.Object)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:58)

"Worker-58" prio=6 tid=0x06ae8400 nid=0x22bc in Object.wait() [0x07a3f000..0x07a3fc94]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:186)
        - locked <0x119d0e98> (a org.eclipse.core.internal.jobs.WorkerPool)
        at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:218)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:51)

"YJPAgent-RequestListener" daemon prio=2 tid=0x06003c00 nid=0x7a18 runnable [0x07eef000..0x07eefa14]
   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketAccept(Native Method)
        at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
        - locked <0x13c9faf0> (a java.net.SocksSocketImpl)
        at java.net.ServerSocket.implAccept(ServerSocket.java:450)
        at java.net.ServerSocket.accept(ServerSocket.java:421)
        at com.yourkit.b.c$1.run(a:16)
        at java.lang.Thread.run(Thread.java:619)

"Timer-2" prio=6 tid=0x05fd3400 nid=0x8ef0 in Object.wait() [0x0713f000..0x0713fb14]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:485)
        at java.util.TimerThread.mainLoop(Timer.java:483)
        - locked <0x131a56f8> (a java.util.TaskQueue)
        at java.util.TimerThread.run(Timer.java:462)

"Timer-1" prio=6 tid=0x06093400 nid=0x5e6c in Object.wait() [0x070ef000..0x070efb94]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:485)
        at java.util.TimerThread.mainLoop(Timer.java:483)
        - locked <0x131a5708> (a java.util.TaskQueue)
        at java.util.TimerThread.run(Timer.java:462)

"Timer-0" prio=6 tid=0x0469ac00 nid=0x85a0 in Object.wait() [0x0709f000..0x0709fc14]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x13172700> (a java.util.TaskQueue)
        at java.lang.Object.wait(Object.java:485)
        at java.util.TimerThread.mainLoop(Timer.java:483)
        - locked <0x13172700> (a java.util.TaskQueue)
        at java.util.TimerThread.run(Timer.java:462)

"Java indexing" daemon prio=4 tid=0x04592400 nid=0x415c in Object.wait() [0x05d4f000..0x05d4fd94]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:485)
        at org.eclipse.jdt.internal.core.search.processing.JobManager.run(JobManager.java:349)
        - locked <0x1240e4c0> (a org.eclipse.jdt.internal.core.search.indexing.IndexManager)
        at java.lang.Thread.run(Thread.java:619)

"Start Level Event Dispatcher" daemon prio=6 tid=0x0377fc00 nid=0x3fa4 in Object.wait() [0x0399f000..0x0399fb94]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x114b1e10> (a org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)
        at java.lang.Object.wait(Object.java:485)
        at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:349)
        - locked <0x114b1e10> (a org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)
        at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:287)

"Framework Event Dispatcher" daemon prio=6 tid=0x037ae800 nid=0x2918 in Object.wait() [0x038af000..0x038afd14]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:485)
        at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:349)
        - locked <0x1149b7a8> (a org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)
        at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:287)

"Low Memory Detector" daemon prio=6 tid=0x02fa9800 nid=0x81b0 runnable [0x00000000..0x00000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=10 tid=0x02fa8000 nid=0x4cfc waiting on condition [0x00000000..0x035af81c]
   java.lang.Thread.State: RUNNABLE

"JDWP Event Helper Thread" daemon prio=6 tid=0x02f9d400 nid=0x1988 runnable [0x00000000..0x00000000]
   java.lang.Thread.State: RUNNABLE

"JDWP Transport Listener: dt_socket" daemon prio=6 tid=0x02f91400 nid=0x8298 runnable [0x00000000..0x00000000]
   java.lang.Thread.State: RUNNABLE

"YJPAgent-CPUSampler" daemon prio=6 tid=0x02f8f400 nid=0x4db0 runnable [0x00000000..0x00000000]
   java.lang.Thread.State: RUNNABLE

"YJPAgent-RequestListener" daemon prio=2 tid=0x02f8c000 nid=0x7650 runnable [0x0345f000..0x0345fa14]
   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketAccept(Native Method)
        at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
        - locked <0x1146f758> (a java.net.SocksSocketImpl)
        at java.net.ServerSocket.implAccept(ServerSocket.java:450)
        at java.net.ServerSocket.accept(ServerSocket.java:421)
        at com.yourkit.runtime.Core$2.run(Core.java:320)
        at java.lang.Thread.run(Thread.java:619)

"YJPAgent-Telemetry" daemon prio=2 tid=0x02f89c00 nid=0x32dc waiting on condition [0x0340f000..0x0340fd94]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
        at java.lang.Thread.sleep(Native Method)
        at com.yourkit.runtime.telemetry.TelemetryThread.run(TelemetryThread.java:272)

"Attach Listener" daemon prio=10 tid=0x02f6a800 nid=0x2e14 runnable [0x00000000..0x00000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x02f69800 nid=0x3df0 waiting on condition [0x00000000..0x00000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=8 tid=0x02f56000 nid=0x2e8c in Object.wait() [0x032bf000..0x032bfa94]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
        - locked <0x1146f7f8> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x02f51800 nid=0x275c in Object.wait() [0x0326f000..0x0326fb14]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:485)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
        - locked <0x1146f818> (a java.lang.ref.Reference$Lock)

"main" prio=6 tid=0x00397000 nid=0x65ec in Object.wait() [0x009df000..0x009dfe68]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:485)
        at org.eclipse.jdt.internal.ui.javaeditor.ASTProvider.getAST(ASTProvider.java:490)
        - locked <0x12587358> (a java.lang.Object)
        at org.eclipse.jdt.internal.ui.javaeditor.JavaEditor.doSelectionChanged(JavaEditor.java:2243)
        at org.eclipse.jdt.internal.ui.javaeditor.JavaEditor$OutlineSelectionChangedListener.selectionChanged(JavaEditor.java:300)
        at org.eclipse.jface.viewers.StructuredViewer$3.run(StructuredViewer.java:841)
        at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:37)
        at org.eclipse.core.runtime.Platform.run(Platform.java:850)
        at org.eclipse.ui.internal.JFaceUtil$1.run(JFaceUtil.java:52)
        at org.eclipse.jface.util.SafeRunnable.run(SafeRunnable.java:153)
        at org.eclipse.jface.viewers.StructuredViewer.firePostSelectionChanged(StructuredViewer.java:839)
        at org.eclipse.jface.viewers.StructuredViewer.handlePostSelect(StructuredViewer.java:1152)
        at org.eclipse.jface.viewers.StructuredViewer$5.widgetSelected(StructuredViewer.java:1172)
        at org.eclipse.jface.util.OpenStrategy.firePostSelectionEvent(OpenStrategy.java:250)
        at org.eclipse.jface.util.OpenStrategy.access$4(OpenStrategy.java:244)
        at org.eclipse.jface.util.OpenStrategy$3.run(OpenStrategy.java:418)
        at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35)
        at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:123)
        - locked <0x10cf3568> (a org.eclipse.swt.widgets.RunnableLock)
        at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:3484)
        at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3124)
        at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2286)
        at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2250)
        at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2125)
        at org.eclipse.ui.internal.Workbench$4.run(Workbench.java:459)
        at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:289)
        at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:454)
        at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149)
        at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:101)
        at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:146)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:106)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:76)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:354)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:169)
        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 org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:476)
        at org.eclipse.equinox.launcher.Main.basicRun(Main.java:416)
        at org.eclipse.equinox.launcher.Main.run(Main.java:1124)
        at org.eclipse.equinox.launcher.Main.main(Main.java:1099)

"VM Thread" prio=10 tid=0x02f4c800 nid=0x3350 runnable

"VM Periodic Task Thread" prio=10 tid=0x02fac400 nid=0x5030 waiting on condition

JNI global references: 11029

Heap
 def new generation   total 17088K, used 16420K [0x100a0000, 0x11320000, 0x11450000)
  eden space 15232K,  95% used [0x100a0000, 0x10ed93f8, 0x10f80000)
  from space 1856K, 100% used [0x10f80000, 0x11150000, 0x11150000)
  to   space 1856K,   0% used [0x11150000, 0x11150000, 0x11320000)
 tenured generation   total 226592K, used 106369K [0x11450000, 0x1f198000, 0x200a0000)
   the space 226592K,  46% used [0x11450000, 0x17c30798, 0x17c30800, 0x1f198000)
 compacting perm gen  total 56832K, used 56607K [0x200a0000, 0x23820000, 0x300a0000)
   the space 56832K,  99% used [0x200a0000, 0x237e7d58, 0x237e7e00, 0x23820000)
No shared spaces configured.
Comment 3 Markus Keller CLA 2007-02-26 10:31:39 EST
Breakpoint at BufferCache(OverflowingLRUCache).makeSpace(int) line: 180:

this	BufferCache  (id=60)	
	fCurrentSpace	51	
	fEntryQueue	LRUCache$LRUCacheEntry  (id=133)	
	fEntryQueueTail	LRUCache$LRUCacheEntry  (id=134)	
	fEntryTable	Hashtable<K,V>  (id=129)	
	fLoadFactor	0.333	
	fOverflow	0	
	fSpaceLimit	60	
	fTimestampCounter	707	
	fTimestampsOn	false	
space	1	
limit	60	
spaceNeeded	40	
entry	LRUCache$LRUCacheEntry  (id=139)	

=> everything except 'entry' is unchanged in successive loop iterations
Comment 4 Markus Keller CLA 2007-02-26 10:44:37 EST
In BufferCache(OverflowingLRUCache).privateRemoveEntry(LRUCache$LRUCacheEntry, boolean, boolean) line: 272:

if (!close(entry)) return;
// buffer close will recursively call #privateRemoveEntry with external==true
// thus entry will already be removed if reaching this point.
if (fEntryTable.get(entry._fKey) == null){
	return;

close(entry) does not recursively call the method, and entry is always found in fEntryTable. I'm not 100% sure, but I think all my CUs were saved (at least line 45 of BufferCache is never hit).
Comment 5 Frederic Fusier CLA 2007-02-26 11:30:02 EST
The fix for bug 128000 was done in CompilationUnit.getContents() which "protected" buffer opening when it was not null (diff between v_644 & v645). In this case, openBuffer is called from CompilationUnit.buildStructure(...) which does not have the same "protection"...
Comment 6 Frederic Fusier CLA 2007-02-26 12:56:18 EST
Previous comment was not 100% correct: the call to openBuffer(...) is done only if buffer != null.

However, the fix for bug 128000 also replaced this call by:
	return Util.getResourceContentsAsCharArray((IFile) getResource());

So, perhaps the solution would be to replace following lines in buildStructure:
// get buffer contents
IBuffer buffer = getBufferManager().getBuffer(CompilationUnit.this);
if (buffer == null) {
	buffer = openBuffer(pm, unitInfo); // open buffer independently from the info, since we are building the info
}
final char[] contents;
if (buffer == null) {
	contents = CharOperation.NO_CHAR ;
} else {
	char[] characters = buffer.getCharacters();
	contents = characters == null ? CharOperation.NO_CHAR : characters;
}

with:
getContents();

The only remaining problem was that no progress monitor would be used during this read action...
Comment 7 Jerome Lanneluc CLA 2007-02-27 09:03:18 EST
To clarify, there was no fix for bug 128000 per se, but the change introduced in I20060307 caused the reported stack trace to become obsolete and thus the bug closed as WORKSFORME.
Comment 8 Jerome Lanneluc CLA 2007-02-27 11:38:32 EST
Looking at the buffer cache code, it appears that it is not thread safe. So several threads adding and removing buffers at the same time could leave this cache in an inconsistent state, which is what - I suspect - happened to Markus.
Comment 9 Jerome Lanneluc CLA 2007-02-27 11:42:08 EST
Created attachment 59886 [details]
Proposed fix

This fix consists in postponing the closing of IBuffers and synchronizing accesses to the buffer cache from the buffer manager. The closing of IBuffers is then done outside the synchronize block to avoid deadlocks.
Comment 10 Jerome Lanneluc CLA 2007-02-27 12:52:44 EST
Proposed fix released for 3.3M6 in HEAD. 
No regression test since this is a concurrency problem.
Please reopen if you see this again.
Comment 11 Jerome Lanneluc CLA 2007-02-28 04:37:44 EST
Improved fix by using a ThreadLocal for the buffers to close to avoid possible race condition in the closeBuffers() method.
Comment 12 Maxime Daniel CLA 2007-03-20 06:22:55 EDT
Verified for 3.3 M6 using v_743.
As noted above, we have no regression test, hence this has been verified by code inspection only. I have specifically checked that the current code for BufferManager takes steps to protect concurrent access to its underlying cache (openBuffers).