Summary: | loading swt+examples with auto-build on causes deadlock (or takes a very long time) | ||
---|---|---|---|
Product: | [Eclipse Project] JDT | Reporter: | Mike Wilson <Mike_Wilson> |
Component: | Core | Assignee: | Philipe Mulet <philippe_mulet> |
Status: | RESOLVED FIXED | QA Contact: | |
Severity: | normal | ||
Priority: | P1 | CC: | jeem, John_Wiegand, kent_johnson, n.a.edgar |
Version: | 2.0 | ||
Target Milestone: | 2.0 M5 | ||
Hardware: | PC | ||
OS: | Windows XP | ||
Whiteboard: |
Description
Mike Wilson
2002-04-10 13:02:24 EDT
Talked to Nick... this appears to be another deadlock case trying to access preferences. Once the builder/compiler start to run & want to report the first error, my machine went completely idle (2% usage). Below is the full thread dump: "Java indexing" daemon prio=5 tid=0xe0f46c0 nid=0x4f4 waiting on monitor [0xf51f 000..0xf51fdbc] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:420) at org.eclipse.core.internal.utils.Semaphore.acquire(Semaphore.java:19) at org.eclipse.core.resources.WorkspaceLock.acquire (WorkspaceLock.java:46) at org.eclipse.ui.internal.UIWorkspaceLock.acquire (UIWorkspaceLock.java:40) at org.eclipse.core.internal.resources.WorkManager.checkIn (WorkManager.java:67) at org.eclipse.core.internal.resources.Workspace.prepareOperation (Workspace.java:1293) at org.eclipse.core.internal.resources.Workspace.run (Workspace.java:1341) at org.eclipse.jdt.internal.core.JavaModelManager.runOperation (JavaModelManager.java:1028) at org.eclipse.jdt.internal.core.JavaElement.runOperation (JavaElement.java:550) at org.eclipse.jdt.internal.core.JavaProject.setRawClasspath (JavaProject.java:1907) at org.eclipse.jdt.core.JavaCore.updateVariableValues (JavaCore.java:1185) at org.eclipse.jdt.core.JavaCore.setClasspathVariables (JavaCore.java:1012) at org.eclipse.jdt.core.JavaCore.setClasspathVariable(JavaCore.java:984) at org.eclipse.jdt.internal.launching.JavaClasspathVariablesInitializer.setJREVaria ble(JavaClasspathVariablesInitializer.java:96) at org.eclipse.jdt.internal.launching.JavaClasspathVariablesInitializer.updateJREVa riables(JavaClasspathVariablesInitializer.java:80) at org.eclipse.jdt.launching.JavaRuntime.updateJREVariables (JavaRuntime.java:261) at org.eclipse.jdt.launching.JavaRuntime.setDefaultVMInstall (JavaRuntime.java:244) at org.eclipse.jdt.launching.JavaRuntime.setDefaultVMInstall (JavaRuntime.java:230) at org.eclipse.jdt.launching.JavaRuntime.detectVMConfiguration (JavaRuntime.java:511) at org.eclipse.jdt.launching.JavaRuntime.initializeVMConfiguration (JavaRuntime.java:491) at org.eclipse.jdt.launching.JavaRuntime.initializeVMTypes (JavaRuntime.java:156) at org.eclipse.jdt.launching.JavaRuntime.getDefaultVMId (JavaRuntime.java:307) at org.eclipse.jdt.launching.JavaRuntime.getDefaultVMInstall (JavaRuntime.java:269) at org.eclipse.jdt.internal.launching.JavaClasspathVariablesInitializer.initialize (JavaClasspathVariablesInitializer.java:34) at org.eclipse.jdt.core.JavaCore.getClasspathVariable(JavaCore.java:339) at org.eclipse.jdt.core.JavaCore.getResolvedVariablePath (JavaCore.java:546) at org.eclipse.jdt.core.JavaCore.getResolvedClasspathEntry (JavaCore.java:465) at org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath (JavaProject.java:1170) at org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath (JavaProject.java:1111) at org.eclipse.jdt.internal.core.JavaProject.computePackageFragmentRoots (JavaProject.java:222) at org.eclipse.jdt.internal.core.JavaProject.computePackageFragmentRoots (JavaProject.java:200) at org.eclipse.jdt.internal.core.JavaProject.updatePackageFragmentRoots (JavaProject.java:1730) at org.eclipse.jdt.internal.core.JavaProject.setRawClasspath0 (JavaProject.java:1936) at org.eclipse.jdt.internal.core.JavaProject.generateInfos (JavaProject.java:592) at org.eclipse.jdt.internal.core.Openable.buildStructure (Openable.java:63) at org.eclipse.jdt.internal.core.Openable.openWhenClosed (Openable.java:394) at org.eclipse.jdt.internal.core.JavaProject.openWhenClosed (JavaProject.java:1536) at org.eclipse.jdt.internal.core.JavaElement.openHierarchy (JavaElement.java:497) at org.eclipse.jdt.internal.core.JavaElement.getElementInfo (JavaElement.java:287) at org.eclipse.jdt.internal.core.JavaProject.getJavaProjectElementInfo (JavaProject.java:759) at org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath (JavaProject.java:1122) at org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath (JavaProject.java:1111) at org.eclipse.jdt.internal.core.search.indexing.IndexManager.indexAll (IndexManager.java:266) at org.eclipse.jdt.internal.core.search.indexing.IndexManager.checkIndexConsistency (IndexManager.java:133) at org.eclipse.jdt.internal.core.search.indexing.IndexManager.activateProcessing (IndexManager.java:57) at org.eclipse.jdt.internal.core.search.processing.JobManager.run (JobManager.java:279) at java.lang.Thread.run(Thread.java:484) "ModalContext" prio=5 tid=0xe09fd08 nid=0x394 waiting for monitor entry [0xf2ff000..0xf2ffdbc] at org.eclipse.jdt.internal.core.JavaElement.getElementInfo (JavaElement.java:285) at org.eclipse.jdt.internal.core.JavaProject.getJavaProjectElementInfo (JavaProject.java:759) at org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath (JavaProject.java:1122) at org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath (JavaProject.java:1111) at org.eclipse.jdt.internal.core.JavaModelManager.determineIfOnClasspath (JavaModelManager.java:249) at org.eclipse.jdt.internal.core.JavaModelManager.createCompilationUnitFrom (JavaModelManager.java:199) at org.eclipse.jdt.internal.core.JavaModelManager.create (JavaModelManager.java:128) at org.eclipse.jdt.internal.core.JavaModelManager.create (JavaModelManager.java:93) at org.eclipse.jdt.core.JavaCore.create(JavaCore.java:277) at org.eclipse.jdt.internal.core.builder.AbstractImageBuilder.storeProblemsFor (AbstractImageBuilder.java:349) at org.eclipse.jdt.internal.core.builder.AbstractImageBuilder.updateProblemsFor (AbstractImageBuilder.java:370) at org.eclipse.jdt.internal.core.builder.AbstractImageBuilder.acceptResult (AbstractImageBuilder.java:90) at org.eclipse.jdt.internal.compiler.Compiler.handleInternalException (Compiler.java:486) at org.eclipse.jdt.internal.compiler.Compiler.compile(Compiler.java:346) at org.eclipse.jdt.internal.core.builder.AbstractImageBuilder.compile (AbstractImageBuilder.java:210) at org.eclipse.jdt.internal.core.builder.AbstractImageBuilder.compile (AbstractImageBuilder.java:157) at org.eclipse.jdt.internal.core.builder.BatchImageBuilder.build (BatchImageBuilder.java:46) at org.eclipse.jdt.internal.core.builder.JavaBuilder.buildAll (JavaBuilder.java:149) at org.eclipse.jdt.internal.core.builder.JavaBuilder.build (JavaBuilder.java:95) at org.eclipse.core.internal.events.BuildManager$2.run (BuildManager.java:383) at org.eclipse.core.internal.runtime.InternalPlatform.run (InternalPlatform.java:838) at org.eclipse.core.runtime.Platform.run(Platform.java:411) at org.eclipse.core.internal.events.BuildManager.basicBuild (BuildManager.java:119) at org.eclipse.core.internal.events.BuildManager.basicBuild (BuildManager.java:173) at org.eclipse.core.internal.events.BuildManager.basicBuild (BuildManager.java:183) at org.eclipse.core.internal.events.BuildManager$1.run (BuildManager.java:143) at org.eclipse.core.internal.runtime.InternalPlatform.run (InternalPlatform.java:838) at org.eclipse.core.runtime.Platform.run(Platform.java:411) at org.eclipse.core.internal.events.BuildManager.basicBuild (BuildManager.java:157) at org.eclipse.core.internal.events.BuildManager.build (BuildManager.java:208) at org.eclipse.core.internal.resources.Workspace.endOperation (Workspace.java:743) at org.eclipse.core.internal.resources.Workspace.run (Workspace.java:1348) at org.eclipse.ui.actions.WorkspaceModifyOperation.run (WorkspaceModifyOperation.java:78) at org.eclipse.jface.operation.ModalContext$ModalContextThread.run (ModalContext.java:98) "SeedGenerator Thread" daemon prio=2 tid=0xe183dc8 nid=0x320 waiting on monitor [0xf28f000..0xf28fdbc] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:420) at sun.security.provider.SeedGenerator.run(SeedGenerator.java:105) at java.lang.Thread.run(Thread.java:484) "Signal Dispatcher" daemon prio=10 tid=0x809618 nid=0x528 waiting on monitor [0..0] "Finalizer" daemon prio=9 tid=0x805818 nid=0x40c waiting on monitor [0xe2af000..0xe2afdbc] at java.lang.Object.wait(Native Method) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:108) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:123) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:162) "Reference Handler" daemon prio=10 tid=0xdff0368 nid=0x4a0 waiting on monitor [0xe26f000..0xe26fdbc] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:420) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:110) "main" prio=5 tid=0x2346e0 nid=0x484 runnable [0x6f000..0x6fc34] at org.eclipse.swt.internal.win32.OS.WaitMessage(Native Method) at org.eclipse.swt.widgets.Display.sleep(Display.java:1621) at org.eclipse.jface.operation.ModalContext$ModalContextThread.block (ModalContext.java:134) at org.eclipse.jface.operation.ModalContext.run(ModalContext.java:258) at org.eclipse.jface.dialogs.ProgressMonitorDialog.run (ProgressMonitorDialog.java:335) at org.eclipse.team.ui.actions.TeamAction.run(TeamAction.java:165) at org.eclipse.team.internal.ccvs.ui.actions.AddToWorkspaceAction.run (AddToWorkspaceAction.java:74) at org.eclipse.ui.internal.PluginAction.runWithEvent (PluginAction.java:204) at org.eclipse.jface.action.ActionContributionItem.handleWidgetSelection (ActionContributionItem.java:407) at org.eclipse.jface.action.ActionContributionItem.handleWidgetEvent (ActionContributionItem.java:361) at org.eclipse.jface.action.ActionContributionItem.access$0 (ActionContributionItem.java:352) at org.eclipse.jface.action.ActionContributionItem$ActionListener.handleEvent (ActionContributionItem.java:47) at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:75) at org.eclipse.swt.widgets.Widget.notifyListeners(Widget.java:637) at org.eclipse.swt.widgets.Display.runDeferredEvents(Display.java:1412) at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:1208) at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:836) at org.eclipse.ui.internal.Workbench.run(Workbench.java:819) at org.eclipse.core.internal.boot.InternalBootLoader.run (InternalBootLoader.java:777) at org.eclipse.core.boot.BootLoader.run(BootLoader.java:319) at java.lang.reflect.Method.invoke(Native Method) at org.eclipse.core.launcher.Main.basicRun(Main.java:190) at org.eclipse.core.launcher.Main.run(Main.java:549) at org.eclipse.core.launcher.Main.main(Main.java:390) "VM Thread" prio=5 tid=0x804308 nid=0x50c runnable "VM Periodic Task Thread" prio=10 tid=0x808348 nid=0x49c waiting on monitor "Suspend Checker Thread" prio=10 tid=0x808c90 nid=0x370 runnable Problem is not caused by the preference changes, but may have been the same as the hang I saw yesterday (I did not have the full picture of all threads yesterday). It looks like a deadlock between the Java indexing and the builder, as follows. (The UI thread is shown, but is not involved in the deadlock). UI thread (main): SWT event loop -> AddToWorkspaceAction -> ModalContext.run -> OS.WaitMessage - sleeping, waiting for message from OS ModalContext thread: WorkspaceModifyOperation -> Workspace (acquires workspace lock) -> Java Builder -> Java Model - waiting on Java model manager, in JavaElement.getElementInfo Java indexing thread: Search JobManager -> IndexManager -> Java Model (acquires Java model manager lock in JavaElement.getElementInfo) -> JavaRuntime (in JDT launching) -> Java Model -> Workspace - waiting on workspace lock To avoid deadlock, locks must be acquired in the same order. Since the builder is invoked via the workspace, the order must be Workspace then Java Model. The indexer must be changed to acquire locks in this order. moving to Java CORE, per Nick's analysis it isn't preferences/UI related. Why is the indexer causing to populate the JavaModel at all ? This should not occur, though it is not directly causing the deadlock (which is due to the activation of the CP initializer which in turns needs the wks lock). Requiring the indexer to acquire the workspace lock might hinder its ability to perform in background. However, it could maybe do so in the case the project classpath wasn't resolved so as to foresee a possible lock access in the CP initializer. But a better approach would be to ensure it never needs the JavaModelManager lock; since never populating. In order to do so, it would not use #getResolvedClasspath, but rather only the raw classpath (if element isn't already open) and manually resolve entries. Proposed fix:
JavaProject
[ /**
* Internal variant which can create marker on project for invalid
entries
*/
public IClasspathEntry[] getResolvedClasspath(
boolean ignoreUnresolvedVariable,
boolean generateMarkerOnError)
throws JavaModelException {
// if project isn't already opened, then no caching is done
// see 13395
JavaProjectElementInfo projectInfo;
if (this.isOpen()){
projectInfo = getJavaProjectElementInfo();
} else {
projectInfo = null;
}
// reuse cache if not needing to refresh markers or checking
bound variables
if (ignoreUnresolvedVariable && !generateMarkerOnError &&
(projectInfo != null)){
// resolved path is cached on its info
IClasspathEntry[] infoPath =
projectInfo.lastResolvedClasspath;
if (infoPath != null) return infoPath;
}
IClasspathEntry[] classpath = getRawClasspath();
if (generateMarkerOnError){
flushClasspathProblemMarkers(false);
}
IClasspathEntry[] resolvedPath = classpath; // clone only if
necessary
int length = classpath.length;
int index = 0;
for (int i = 0; i < length; i++) {
IClasspathEntry entry = classpath[i];
/* validation if needed */
if (generateMarkerOnError) {
IJavaModelStatus status =
JavaConventions.validateClasspathEntry
(this, entry, false);
if (!status.isOK())
createClasspathProblemMarker(
status.getMessage(),
IMarker.SEVERITY_ERROR,
false);
}
/* resolve variables if any, unresolved ones are
ignored */
if (entry.getEntryKind() ==
IClasspathEntry.CPE_VARIABLE) {
// clone original path
if (resolvedPath == classpath) {
System.arraycopy(
classpath,
0,
resolvedPath = new
IClasspathEntry[length],
0,
i);
}
// resolve current variable (handling variable-
>variable->variable->entry
IPath variablePath = entry.getPath(); // for
error reporting
entry = JavaCore.getResolvedClasspathEntry
(entry);
if (entry == null) {
if (!ignoreUnresolvedVariable) {
throw new JavaModelException(
new JavaModelStatus(
IJavaModelStatusConstants.CP_VARIABLE_PATH_UNBOUND,
variablePath.toString()));
}
}
}
if (entry != null) {
resolvedPath[index++] = entry;
}
}
// resize resolved classpath in case some variable entries
could not be resolved
if (index != length) {
System.arraycopy(
resolvedPath,
0,
resolvedPath = new IClasspathEntry[index],
0,
index);
}
if (projectInfo != null){
projectInfo.lastResolvedClasspath = resolvedPath;
}
return resolvedPath;
}
]
Checked that the proposed fix does solve this scenario. Thanks McQ for the excellent test case, and Nick for your analysis. Will be released into next integration build (thursday's). Fixed Also changed the project indexing (occurring in background) to avoid triggering classpath resolution if the project is closed. We don't want to run CP initializers in the background, just to find more libraries to index. These can be found normally when variables are initialized anyway. |