search

eclipse / xtext

Eclipse Xtext™ is a language development framework
http://www.eclipse.org/Xtext
Eclipse Public License 2.0
768 stars 321 forks source link

Potential deadlock with Parallel Resource loading #2431

Open cdietrich opened 4 years ago

cdietrich commented 4 years ago

we have a potential deadlock with Parallel Resource loading

waits for workspace lock and blocks other accesses to PackageFragmentRootData

Thread[pool-309-thread-2,5,main], state: TIMED_WAITING
    java.base@11.0.8/java.lang.Object.wait(Native Method)
    org.eclipse.core.internal.jobs.Semaphore.acquire(Semaphore.java:44)
    org.eclipse.core.internal.jobs.OrderedLock.doAcquire(OrderedLock.java:173)
    org.eclipse.core.internal.jobs.OrderedLock.acquire(OrderedLock.java:109)
    org.eclipse.core.internal.jobs.OrderedLock.acquire(OrderedLock.java:85)
    org.eclipse.core.internal.resources.WorkManager.checkIn(WorkManager.java:125)
    org.eclipse.core.internal.resources.Workspace.prepareOperation(Workspace.java:2242)
    org.eclipse.core.internal.resources.Workspace.run(Workspace.java:2287)
    org.eclipse.core.internal.resources.Workspace.run(Workspace.java:2317)
    org.eclipse.jdt.internal.core.JavaModelManager.initializeAllContainers(JavaModelManager.java:3142)
    org.eclipse.jdt.internal.core.JavaModelManager.getClasspathContainer(JavaModelManager.java:2111)
    org.eclipse.jdt.core.JavaCore.getClasspathContainer(JavaCore.java:3747)
    org.eclipse.jdt.internal.core.JavaProject.resolveClasspath(JavaProject.java:3175)
    org.eclipse.jdt.internal.core.JavaProject.resolveClasspath(JavaProject.java:3339)
    org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath(JavaProject.java:2423)
    org.eclipse.jdt.internal.core.JavaProject.getClasspathEntryFor(JavaProject.java:1842)
    org.eclipse.jdt.internal.core.PackageFragmentRoot.getHandleMemento(PackageFragmentRoot.java:511)
    org.eclipse.jdt.internal.core.JavaElement.getHandleMemento(JavaElement.java:362)
    org.eclipse.jdt.internal.core.JavaElement.getHandleIdentifier(JavaElement.java:355)
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl$PackageFragmentRootData.addRoot(Storage2UriMapperJavaImpl.java:111)
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.getCachedData(Storage2UriMapperJavaImpl.java:260)
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.getData(Storage2UriMapperJavaImpl.java:248)
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.getAllEntries(Storage2UriMapperJavaImpl.java:241)
    org.eclipse.xtext.ui.resource.JavaProjectResourceSetInitializer.computePlatformURIMap(JavaProjectResourceSetInitializer.java:79)
    org.eclipse.xtext.ui.resource.JavaProjectResourceSetInitializer.initialize(JavaProjectResourceSetInitializer.java:51)
    custom.CustomJavaProjectResourceSetInitializer.initialize(ParLibraryResourceSetInitializer.java:36)
    org.eclipse.xtext.ui.resource.XtextResourceSetProvider.get(XtextResourceSetProvider.java:54)
    org.eclipse.xtext.builder.resourceloader.ParallelResourceLoader$ParallelLoadOperation$1.initialValue(ParallelResourceLoader.java:154)

waits

    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.getStorages(Storage2UriMapperJavaImpl.java:363)
    org.eclipse.xtext.ui.resource.Storage2UriMapperImpl$2$1.apply(Storage2UriMapperImpl.java:139)
    org.eclipse.xtext.ui.resource.Storage2UriMapperImpl$2$1.apply(Storage2UriMapperImpl.java:1)
    com.google.common.collect.Lists$TransformingRandomAccessList$1.transform(Lists.java:612)
    com.google.common.collect.TransformedIterator.next(TransformedIterator.java:47)
    com.google.common.collect.TransformedIterator.next(TransformedIterator.java:47)
    com.google.common.collect.Iterators$ConcatenatedIterator.hasNext(Iterators.java:1330)
    org.eclipse.xtext.ui.editor.WorkspaceEncodingProvider.getEncoding(WorkspaceEncodingProvider.java:64)
    org.eclipse.xtext.resource.XtextResource.getEncoding(XtextResource.java:205)
    org.eclipse.xtext.resource.XtextResource.createReader(XtextResource.java:191)
    org.eclipse.xtext.resource.XtextResource.doLoad(XtextResource.java:177)
    org.eclipse.xtext.linking.lazy.LazyLinkingResource.doLoad(LazyLinkingResource.java:115)
    custom.CustomXtextResource.doLoad(TplXtextResource.java:105)
    org.eclipse.emf.ecore.resource.impl.ResourceImpl.load(ResourceImpl.java:1563)
    org.eclipse.emf.ecore.resource.impl.ResourceImpl.load(ResourceImpl.java:1342)
    org.eclipse.emf.ecore.resource.impl.ResourceSetImpl.demandLoad(ResourceSetImpl.java:259)
    org.eclipse.emf.ecore.resource.impl.ResourceSetImpl.demandLoadHelper(ResourceSetImpl.java:274)
    org.eclipse.xtext.resource.XtextResourceSet.getResource(XtextResourceSet.java:266)
    org.eclipse.xtext.resource.SynchronizedXtextResourceSet.getResource(SynchronizedXtextResourceSet.java:25)
    org.eclipse.xtext.builder.resourceloader.AbstractResourceLoader.loadResource(AbstractResourceLoader.java:47)

this one may invalidate the classpath

Thread[Worker-0: Updating workspace,5,main], state: BLOCKED
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.getCachedData(Storage2UriMapperJavaImpl.java:256)
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.updateCache(Storage2UriMapperJavaImpl.java:481)
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.elementChanged(Storage2UriMapperJavaImpl.java:442)
    org.eclipse.jdt.internal.core.DeltaProcessor$3.run(DeltaProcessor.java:1755)
    org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
    org.eclipse.jdt.internal.core.DeltaProcessor.notifyListeners(DeltaProcessor.java:1743)
    org.eclipse.jdt.internal.core.DeltaProcessor.firePostChangeDelta(DeltaProcessor.java:1576)
    org.eclipse.jdt.internal.core.DeltaProcessor.fire(DeltaProcessor.java:1552)
    org.eclipse.jdt.internal.core.DeltaProcessor.notifyAndFire(DeltaProcessor.java:2273)
    org.eclipse.jdt.internal.core.DeltaProcessor.resourceChanged(DeltaProcessor.java:2163)
    org.eclipse.jdt.internal.core.DeltaProcessingState.resourceChanged(DeltaProcessingState.java:477)
    org.eclipse.core.internal.events.NotificationManager$1.run(NotificationManager.java:305)
    org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
    org.eclipse.core.internal.events.NotificationManager.notify(NotificationManager.java:295)
    org.eclipse.core.internal.events.NotificationManager.broadcastChanges(NotificationManager.java:158)
    org.eclipse.core.internal.resources.Workspace.broadcastPostChange(Workspace.java:380)
    org.eclipse.core.internal.resources.Workspace.endOperation(Workspace.java:1502)
    org.eclipse.core.internal.resources.Workspace.run(Workspace.java:2306)
    org.eclipse.core.internal.events.NotificationManager$NotifyJob.run(NotificationManager.java:44)
    org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)

this one owns the workspace lock, but is blocked by the load operation waiting for the workspace lock

Thread[ModalContext,6,main], state: BLOCKED
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.getCachedData(Storage2UriMapperJavaImpl.java:256)
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.getData(Storage2UriMapperJavaImpl.java:248)
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.getAllEntries(Storage2UriMapperJavaImpl.java:241)
    org.eclipse.xtext.ui.containers.JavaProjectsStateHelper.initContainedURIs(JavaProjectsStateHelper.java:87)
    custom.CustomJavaProjectsStateHelper.initContainedURIs(TplJavaProjectsStateHelper.java:174)
    org.eclipse.xtext.ui.containers.JavaProjectsState.doInitContainedURIs(JavaProjectsState.java:33)
    org.eclipse.xtext.ui.containers.AbstractAllContainersState.initContainedURIs(AbstractAllContainersState.java:151)
    org.eclipse.xtext.ui.containers.AbstractAllContainersState.isEmpty(AbstractAllContainersState.java:147)
    org.eclipse.xtext.resource.containers.ContainerState.isEmpty(ContainerState.java:36)
    org.eclipse.xtext.resource.containers.StateBasedContainer.isEmpty(StateBasedContainer.java:82)
    org.eclipse.xtext.resource.containers.StateBasedContainerManager.getVisibleContainers(StateBasedContainerManager.java:110)
    org.eclipse.xtext.resource.containers.StateBasedContainerManager.getVisibleContainers(StateBasedContainerManager.java:67)
    org.eclipse.xtext.scoping.impl.DefaultGlobalScopeProvider.getVisibleContainers(DefaultGlobalScopeProvider.java:73)
    org.eclipse.xtext.scoping.impl.DefaultGlobalScopeProvider.getScope(DefaultGlobalScopeProvider.java:50)
    org.eclipse.xtext.scoping.impl.DefaultGlobalScopeProvider.getScope(DefaultGlobalScopeProvider.java:62)
    org.eclipse.xtext.scoping.impl.AbstractGlobalScopeProvider.getScope(AbstractGlobalScopeProvider.java:51)
    custom.CustomTypesAwareDefaultGlobalScopeProvider.getScope(TplTypesAwareDefaultGlobalScopeProvider.java:53)
    org.eclipse.xtext.scoping.impl.AbstractGlobalScopeDelegatingScopeProvider.getGlobalScope(AbstractGlobalScopeDelegatingScopeProvider.java:47)
    custom.CustomImportedNamespaceAwareLocalScopeProvider.getGlobalScope(TplImportedNamespaceAwareLocalScopeProvider.java:786)
    custom.CustomImportedNamespaceAwareLocalScopeProvider.getResourceScope(TplImportedNamespaceAwareLocalScopeProvider.java:503)
    org.eclipse.xtext.scoping.impl.ImportedNamespaceAwareLocalScopeProvider.getScope(ImportedNamespaceAwareLocalScopeProvider.java:98)
    custom.CustomImportedNamespaceAwareLocalScopeProvider.getScope(TplImportedNamespaceAwareLocalScopeProvider.java:381)
    org.eclipse.xtext.scoping.impl.ImportedNamespaceAwareLocalScopeProvider.getScope(ImportedNamespaceAwareLocalScopeProvider.java:96)
    custom.CustomImportedNamespaceAwareLocalScopeProvider.getScope(TplImportedNamespaceAwareLocalScopeProvider.java:381)
    custom.CustomScopeProvider$6.apply(TplScopeProvider.java:357)
    custom.CustomScopeProvider$6.apply(TplScopeProvider.java:1)
    custom.CustomExtensions$1.get(TplExtensions.java:104)
    org.eclipse.xtext.util.OnChangeEvictingCache.get(OnChangeEvictingCache.java:77)
    custom.CustomScopeProvider.getTerminalScope(TplScopeProvider.java:368)
    custom.CustomScopeProvider.scope_TerminalReference_target(TplScopeProvider.java:323)
    jdk.internal.reflect.GeneratedMethodAccessor62.invoke(Unknown Source)
    java.base@11.0.8/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    java.base@11.0.8/java.lang.reflect.Method.invoke(Method.java:566)
    org.eclipse.xtext.util.PolymorphicDispatcher.invoke(PolymorphicDispatcher.java:303)
    org.eclipse.xtext.scoping.impl.AbstractDeclarativeScopeProvider.polymorphicFindScopeForReferenceName(AbstractDeclarativeScopeProvider.java:153)
    org.eclipse.xtext.scoping.impl.AbstractDeclarativeScopeProvider.getScope(AbstractDeclarativeScopeProvider.java:101)
    custom.CustomScopeProvider.getScope(TplScopeProvider.java:225)
    org.eclipse.xtext.linking.impl.DefaultLinkingService.getScope(DefaultLinkingService.java:59)
    custom.CustomLinkingService.getLinkedObjects(TplLinkingService.java:44)
    custom.CustomXtextResource.getEObject(TplXtextResource.java:243)
    org.eclipse.xtext.linking.lazy.LazyLinkingResource.getEObject(LazyLinkingResource.java:237)
    org.eclipse.xtext.linking.lazy.LazyLinkingResource.doResolveLazyCrossReference(LazyLinkingResource.java:204)
    org.eclipse.xtext.linking.lazy.LazyLinkingResource.resolveLazyCrossReference(LazyLinkingResource.java:163)
    org.eclipse.xtext.linking.lazy.LazyLinkingResource.resolveLazyCrossReferences(LazyLinkingResource.java:149)
    org.eclipse.xtext.EcoreUtil2.resolveLazyCrossReferences(EcoreUtil2.java:505)
    custom.CustomBuilderState.internalDoUpdate(ClusteringBuilderState93k.java:689)
    custom.CustomBuilderState.doUpdate(ClusteringBuilderState93k.java:401)
    org.eclipse.xtext.builder.builderState.AbstractBuilderState.update(AbstractBuilderState.java:153)
    org.eclipse.xtext.builder.impl.XtextBuilder.doBuild(XtextBuilder.java:388)
cdietrich commented 4 years ago

@iloveeclipse did some more analysis during the build it is possible to run other jobs on the workspace cause it does a getWorkManager().beginUnprotected(); now NotifyJob comes in an "steals" that lock so the builder thread and the loader thread cannot aquire it to do the actual work of working with Storage2UriMapperJavaImpl data. so if we are unlucky, one of these will aquire the synchronized (cachedPackageFragmentRootData) so that NotifyJob cannot aquire this synchronized lock and so both will block each other.

we will try to offload the work of org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.elementChanged(ElementChangedEvent) to a separate job.

@szarnekow do you have some usecases in mind where late invalidation or updating of the data cache might be a problem

cdietrich commented 4 years ago

maybe we also need to do some similar magic like

org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.initializeCache(boolean)

for all modify operations

and make the read ops not needing a synchonized

cdietrich commented 4 years ago

if the NotifyJob happens async "somewhen" then i wonder if e.g. org.eclipse.xtext.builder.impl.javasupport.JdtToBeBuiltComputer.updateProject(ToBeBuilt, IProject, IProgressMonitor) might see outdated classpath and thus miss model files in jars on classpath

iloveeclipse commented 4 years ago

Processing change events on workspace notification thread is a problem, because it holds that workspace lock and Storage2UriMapperJavaImpl will try to lock via cachedPackageFragmentRootData field. That is a road for deadlocks.

As discussed, NotificationManager$NotifyJob can run in parallel to build because they use two different locks. The trick is that Workspace.run() first locks the workspace resource via rule (in getWorkManager().checkIn(rule, monitor)) and after that unlocks the global workspace lock via getWorkManager().beginUnprotected(); NotifyJob however uses a "null" rule, so it owns the global workspace lock but does not lock any resource via rule. So the JavaModelManager.initializeAllContainers also uses a null rule, it also calls workspace.run() but here it collides with the NotificationManager job that already owns global workspace lock.

Therefore my original root cause assessment was wrong, I will update the description about threads involved in the deadlock.

So the probably easiest solution for Xtext is to decouple Storage2UriMapperJavaImpl.elementChanged / Storage2UriMapperJavaImpl.updateCache work from the resource notification thread, so we can't own workspace lock and try to acquire Storage2UriMapperJavaImpl lock at same time.

We've tried to replace Storage2UriMapperJavaImpl with our own implementation that simply runs a separated job on Storage2UriMapperJavaImpl.elementChanged, but that runs in a sporadic test issues because it tried then to update cache for already deleted projects.

So ideally update cache would either not require hard "synchronized" lock (use ILock for example, that could be interrupted) or not lock at all (may be call the problematic code that tries to resolve classpath at different time?).

Below is also the main problem source:

Thread[Worker-4: Updating workspace,5,main], state: BLOCKED
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.getCachedData(Storage2UriMapperJavaImpl.java:256)
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.updateCache(Storage2UriMapperJavaImpl.java:481)
    org.eclipse.xtext.ui.resource.Storage2UriMapperJavaImpl.elementChanged(Storage2UriMapperJavaImpl.java:442)
    org.eclipse.jdt.internal.core.DeltaProcessor$3.run(DeltaProcessor.java:1755)
    org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
    org.eclipse.jdt.internal.core.DeltaProcessor.notifyListeners(DeltaProcessor.java:1743)
    org.eclipse.jdt.internal.core.DeltaProcessor.firePostChangeDelta(DeltaProcessor.java:1576)
    org.eclipse.jdt.internal.core.DeltaProcessor.fire(DeltaProcessor.java:1552)
    org.eclipse.jdt.internal.core.DeltaProcessor.notifyAndFire(DeltaProcessor.java:2273)
    org.eclipse.jdt.internal.core.DeltaProcessor.resourceChanged(DeltaProcessor.java:2163)
    org.eclipse.jdt.internal.core.DeltaProcessingState.resourceChanged(DeltaProcessingState.java:477)
    org.eclipse.core.internal.events.NotificationManager$1.run(NotificationManager.java:305)
    org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
    org.eclipse.core.internal.events.NotificationManager.notify(NotificationManager.java:295)
    org.eclipse.core.internal.events.NotificationManager.broadcastChanges(NotificationManager.java:158)
    org.eclipse.core.internal.resources.Workspace.broadcastPostChange(Workspace.java:380)
    org.eclipse.core.internal.resources.Workspace.endOperation(Workspace.java:1502)
    org.eclipse.core.internal.resources.Workspace.run(Workspace.java:2306)
    org.eclipse.core.internal.events.NotificationManager$NotifyJob.run(NotificationManager.java:44)
    org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)
cdietrich commented 4 years ago

SIde note: JDT changed the behaviour of getHandleIdentifier last year to do a resolveClasspath which might have terribly accelerated the problem (asked at jdt-dev, lets see that they say)