Community
Participate
Working Groups
On the 0409 build, I performed the following steps. - new workspace - enable "Perform build automatically..." - connect to open source repository - select all of the following projects in the HEAD stream: org.eclipse.swt org.eclipse.swt.examples org.eclipse.swt.examples.controls org.eclipse.swt.examples.launcher org.eclipse.swt.examples.layouts org.eclipse.swt.examples.ole.win32 org.eclipse.swt.examples.paint - do "Check out as project" At this point, the progress dialog comes up indicating that the resources are being added, etc. Everything proceeds normally until you get to the "compiling" step, which seems to never complete (I waited approx. 40 minutes). However, if you perform the following steps... - new workspace - disable "Perform build automatically..." - connect to open source repository - select all of the following projects in the HEAD stream: org.eclipse.swt org.eclipse.swt.examples org.eclipse.swt.examples.controls org.eclipse.swt.examples.launcher org.eclipse.swt.examples.layouts org.eclipse.swt.examples.ole.win32 org.eclipse.swt.examples.paint - do "Check out as project" (does not take very long) - Select Project menu -> "Rebuild All" ... you will see that the rebuild operation is quite quick (say, less than 1 minute) including the time to put all 7,058 errors in the task list. I believe the same amount of work ought to be happening in each case, so I suspect there may be something wrong. This is repeatable on my machine, and on another machine running Win2K. My workspace was on my local C: drive.
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.
Undoing the latter change, since it may cause some indexes to be missed if corresponding projects are not yet opened (see bug 19303). Better fix is to ensure that the involved variables are resolved from the calling thread.
