Community
Participate
Working Groups
Build ID: M20071023-1652 I could reproduce a deadlock during Eclipse startup. From my analysis this is what happened: 1) JDT/Core had just spawned the indexer (which was still "warming-up") 2) the Activator of a third-party plug-in, here com.soyatec.uml.core_2.1.0, called JavaCore.setOptions(Hashtable) Eventually the indexer thread needed to load a class (here: Index). Concurrently JavaCore had to wait for the indexes to be ready. Since I need to run Eclipse with the global classloading lock (osgi.classloader.singleThreadLoads=true, see bug 121737) to avoid other deadlocks, the Activator of the uml plug-in blocks any classloading by other classloaders. => Indexer is waiting for class loading, => class loader waits for bundle activator waits for indexer. I paste the relevant stacktraces below. Since this deadlock involves three parties (JDT/Core, equinox singleThreadLoads, and the uml plug-in) it's not me to decide, who's wrong. Since doing heavy work in an Activator is bad style, I feel that JavaCore should communicate to clients, that seemingly harmless methods like setOptions may indeed perform heavy work, which should never be invoked from an Activator. My workaround was simply to disable the uml plug-in (which I wasn't using very frequently any way, see the old version number 2.1.0 ;-) Finally, here are the stacks: Daemon Thread [Java indexing] (Suspended) owns: IndexManager (id=78) waiting for: DefaultClassLoader (id=80) Object.wait(long) line: not available [native method] DefaultClassLoader(Object).wait() line: 485 BundleLoader.lock(Object) line: 1089 BundleLoader.findClass(String, boolean) line: 383 BundleLoader.findClass(String) line: 372 DefaultClassLoader.loadClass(String, boolean) line: 83 DefaultClassLoader(ClassLoader).loadClass(String) line: 251 DefaultClassLoader(ClassLoader).loadClassInternal(String) line: 319 IndexManager.getIndex(IPath, IPath, boolean, boolean) line: 257 IndexManager.getIndexForUpdate(IPath, boolean, boolean) line: 277 AddJarFileToIndex.execute(IProgressMonitor) line: 75 IndexManager(JobManager).run() line: 392 Thread.run() line: 619 Thread [main] (Suspended) owns: RunnableLock (id=79) owns: RunnableLock (id=77) waiting for: IndexManager (id=78) IndexManager(JobManager).discardJobs(String) line: 83 ClasspathChange.requestIndexing() line: 452 SetContainerOperation(ChangeClasspathOperation).classpathChanged(JavaProject) line: 66 SetContainerOperation.executeOperation() line: 112 SetContainerOperation(JavaModelOperation).run(IProgressMonitor) line: 720 SetContainerOperation(JavaModelOperation).runOperation(IProgressMonitor) line: 780 JavaCore.java line: 4538 RequiredPluginsInitializer.initialize(IPath, IJavaProject) line: 33 JavaModelManager.initializeContainer(IJavaProject, IPath) line: 2218 JavaModelManager$7.run(IProgressMonitor) line: 2148 JavaModelManager.initializeAllContainers(IJavaProject, IPath) line: 2162 JavaModelManager.getClasspathContainer(IPath, IJavaProject) line: 1544 JavaCore.java line: 1590 JavaProject.resolveClasspath(JavaModelManager$PerProjectInfo) line: 2570 JavaProject.getResolvedClasspath() line: 1860 DeltaProcessingState.initializeRoots() line: 202 SetContainerOperation(JavaModelOperation).run(IProgressMonitor) line: 717 SetContainerOperation(JavaModelOperation).runOperation(IProgressMonitor) line: 780 JavaCore.java line: 4538 JREContainerInitializer.initialize(IPath, IJavaProject) line: 69 JavaModelManager.initializeContainer(IJavaProject, IPath) line: 2218 JavaModelManager.getClasspathContainer(IPath, IJavaProject) line: 1546 JavaCore.java line: 1590 JavaProject.resolveClasspath(JavaModelManager$PerProjectInfo) line: 2570 JavaProject.getResolvedClasspath() line: 1860 DeltaProcessor.createExternalArchiveDelta(IProgressMonitor) line: 802 DeltaProcessor.resourceChanged(IResourceChangeEvent) line: 1897 DeltaProcessingState.resourceChanged(IResourceChangeEvent) line: 368 NotificationManager$2.run() line: 282 SafeRunner.run(ISafeRunnable) line: 37 NotificationManager.notify(ResourceChangeListenerList$ListenerEntry[], IResourceChangeEvent, boolean) line: 276 NotificationManager.broadcastChanges(ElementTree, ResourceChangeEvent, boolean) line: 148 Workspace.broadcastPostChange() line: 311 Workspace.endOperation(ISchedulingRule, boolean, IProgressMonitor) line: 1018 Project.touch(IProgressMonitor) line: 1042 JavaModelManager$EclipsePreferencesListener.preferenceChange(IEclipsePreferences$PreferenceChangeEvent) line: 1276 EclipsePreferences$2.run() line: 746 SafeRunner.run(ISafeRunnable) line: 37 InstancePreferences(EclipsePreferences).firePreferenceEvent(String, Object, Object) line: 749 InstancePreferences(EclipsePreferences).put(String, String) line: 762 JavaModelManager.setOptions(Hashtable) line: 4112 JavaCore.java line: 4708 UMLPlugin.a() line: 84 [local variables unavailable] UMLPlugin.start(BundleContext) line: 149 BundleContextImpl$2.run() line: 999 AccessController.doPrivileged(PrivilegedExceptionAction<T>) line: not available [native method] BundleContextImpl.startActivator(BundleActivator) line: 993 ... more ...
I tried to reproduce this issue and never was able to. Two questions about the given stack trace: 1) it seems to have strange lines: - JavaCore.java line: 4708 - JavaCore.java line: 4538 - JavaCore.java line: 1590 and none of these lines matches java code in JavaCore.java R3_3_1 version... How did you get it and are your sure you were using the referred build ID? 2) I do not see another thread requesting a class loader which may explain the lock. Can you attach to this bug the complete stack trace?
Created attachment 87434 [details] corrected stacktrace I'm sorry about incomplete/incorrect information! I forgot that we do have a few source level changes in classes JavaCore, JavaProject and JavaModelManager. I strongly believe that these changes are unrelated to the observed deadlock, but line numbers are broken wrt. any version in your CVS. Sorry (plus the debugger swallowed some method names/signatures due to our use of JSR 045, but that's not a bug..) I currently sit at a different computer, so I cannot easily reproduce, but I tried to translate broken line number information back to a clean state as of v_780. Please excuse if I made mistakes during this manual correction. > 2) I do not see another thread requesting a class loader which may explain > the lock. Can you attach to this bug the complete stack trace? Sorry again for the incomplete stacktrace. Let me try to explain better (for the lack of a more complete stacktrace, currently): Due to the global locking strategy, thread [Java indexing] tries to acquire the global classloading lock using BundleLoader.lock(Object). However, this global lock is owned by thread [main] because startActivator at the bottom of stack [main] is called from within class-loading. Stackframes of thread [main] mentioning BundleLoader omitted at "... more ..." :( I did hope you could quickly confirm that calling JavaCore-methods from within an Activator might be dangerous. If you do want to reproduce I suggest the following (perhaps not telling much news here): + In the launch config pass option "-Dosgi.classloader.singleThreadLoads=true" as a vmarg. + have a workspace with some indexing to be done a startup + set a breakpoint at the first line of IndexManager.reset() => once hit, we have the lock on IndexManager + set another breakpoint at UMLPlugin.start() (or whatever client you use to trigger setOptions from) => once hit, this thread has the classloading lock + Now launch to run up-to these two breakpoints + now set a breakpoint at JobManager.discardJobs(String) and resume [main], which should eventually hit the new breakpoint, but should not be able to enter the "synchronized(this)" block, if "this" is the IndexManager + resume thread [Java indexing] and hope it needs to do some class loading. Do you see it?
Created attachment 88076 [details] stacktrace showing reproducable deadlock in jdt.debug.tests I attach a stacktrace that I get reproducably when running jdt.debug.tests in an unmodified Eclipse 3.3.0. Slightly different situation by symptoms appear to be the same as before.
Steps for reproducing the stacktrace I just attached: 1. Clean Eclipse 3.3 with two projects in the workspace: org.eclipse.test.performance org.eclipse.jdt.debug.tests 2. Launch configuration (JUnit Plugin Tests) with these settings Project: org.eclipse.jdt.debug.tests Test class: org.eclipse.jdt.debug.tests.AutomatedSuite Run an application: org.eclipse.ui.ide.Workbench VM Arguments: -Dosgi.classloader.singleThreadLoads=true Everything else at defaults. 3. Set the following line breakpoints (maybe not all are needed, but this set is dead-safe): ContentDescriptionManager [line: 438] - setCacheState(byte) IndexManager [line: 255] - getIndex(IPath, IPath, boolean, boolean) LaunchingPlugin [line: 479] - start(BundleContext) SourceIndexer [line: 45] - indexDocument() Debug the above launch configuration, see the debugger stop at breakpoints, after waiting a little, resume, and watch the process getting locked in a state, where some threads are actively looping a dead loop, i.e., waiting for an unreachable state. Stacktraces are a little different from previous stacks, but I see these common ingredients: + Indexer is working, trying to load a class, blocked + Other plugin's Activator (here LaunchingPlugin) calls JavaCore.setOptions, which tries to schedule a Job, blocked while blocking class loading. The part I don't see is how Job scheduling contributes to the dead state.
I can reproduce with 3.3 but not with 3.4M4. So, some changes in the Equinox framework seemed to have fix this issue => move to Equinox/Framework component to identify which one and set as duplicate...
So far I have not been able to reproduce on either 3.3 or 3.4. I'm not aware of a fix that would have helped with this deadlock.
OK, I found a significant difference in HEAD: three lines deleted from org.eclipse.jdt.debug.tests.AbstractDebugTest (at the end of <init>): if (!(this.getClass() == ProjectCreationDecorator.class) && !getJavaProject().exists()) { new TestSuite(ProjectCreationDecorator.class).run(new TestResult()); } If you re-add these lines, the deadlock can still be reproduced in 3.4M6. Run to the following breakpoints: thread main: LaunchingPlugin.start(BundleContext) line: 472 thread Java indexing: IndexManager.getIndex(IPath, IPath, boolean, boolean) line: 265 Try to step the main thread past the invocation of JavaCore.setOptions(optionsMap); This thread will hang while trying to schedule an indexer job. Now continue stepping the indexer thread, which will cause loading some more classes (I see org.eclipse.jdt.internal.core.search.indexing.ReadWriteMonitor) which blocks in BundleLoader.lock(Object) line: 1158 (Note that I'm running with singleThreadLoads=true). Does this help you reproduce in 3.4?
Given that osgi.classloader.singleThreadLoads is mostly dead (cf. bug 227587), I assume this issue became irrelevant, too, since the deadlock was observed only with osgi.classloader.singleThreadLoads=true Should it then be closed as WONTFIX?
closing as per previous comment.
