Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Potential deadlock with Parallel Resource loading #2431

Open
cdietrich opened this issue Oct 21, 2020 · 5 comments
Open

Potential deadlock with Parallel Resource loading #2431

cdietrich opened this issue Oct 21, 2020 · 5 comments

Comments

@cdietrich
Copy link
Member

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
Copy link
Member Author

@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
Copy link
Member Author

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
Copy link
Member Author

cdietrich commented Oct 21, 2020

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
Copy link
Contributor

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
Copy link
Member Author

cdietrich commented Oct 27, 2020

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)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants