Bug 548456 - Race condition in JavaElement.exists() and JavaModelCacheI20190626-1800I20190626-0720

Concurrent calls to BinaryType.exists() can sometimes result in false
for one of the callers, despite the type existing.

This is the case due to the two-cache approach in JavaModelManager - it
has thread local JavaModelManager.temporaryCache and global shared
JavaModelManager.cache.

Given two threads calling BinaryType.exists() and nothing is in the
global cache, the 1st thread adds the necessary types to the shared
JavaModelManager.cache via JavaElement.openWhenClosed(), while the 2nd
thread enters JavaElement.openWhenClosed() and is at the beginning of
SourceRefElement.generateInfos().

In the SourceRefElement.generateInfos() 2nd thread then finds element
info for the parent of the BinaryType and assumes there is nothing to be
done, so it leaves the local JavaModelManager.temporaryCache empty.

After the call of SourceRefElement.generateInfos()
JavaElement.openWhenClosed() can't find anything in the local cache and
throws a JavaModelException which causes BinaryType.exists() to return
"false", which is wrong and not expected by the caller.

With this change, JavaElement.openWhenClosed() takes this case into
account and double checks with the JavaModelManager if no info was
generated during JavaElement.generateInfos(). This ensures that no
exception is thrown and that the correct element info is returned by
JavaElement.openWhenClosed(). Without the exception, BinaryType.exists()
returns true as expected.

This change also adds a test which can sometimes show the behavior with
sufficient repetition, if no fix is applied.

To observe the problem manually:

1. set repetition in the test to 1
2. set a breakpoint at the start of: SourceRefElement.generateInfos()
3. run the test
4. resume one of the threads at the breakpoint from 2.
5. resume the other thread at the breakpoint from 2.
6. observe that BinaryType.exists() returns false for the 2nd thread

Change-Id: Id576dd5eabfa060277ab31a9c7eb8da05ce71410
Signed-off-by: Simeon Andreev <simeon.danailov.andreev@gmail.com>
Signed-off-by: Andrey Loskutov <loskutov@gmx.de>

6 files changed, 209 insertions, 0 deletions

diff --git a/org.eclipse.jdt.core.tests.model/src/org/eclipse/jdt/core/tests/model/AllJavaModelTests.java b/org.eclipse.jdt.core.tests.model/src/org/eclipse/jdt/core/tests/model/AllJavaModelTests.java
index 5f37bc32c8..487061a824 100644
--- a/org.eclipse.jdt.core.tests.model/src/org/eclipse/jdt/core/tests/model/AllJavaModelTests.java
+++ b/org.eclipse.jdt.core.tests.model/src/org/eclipse/jdt/core/tests/model/AllJavaModelTests.java
@@ -219,6 +219,8 @@ private static Class[] getAllTestClasses() {
 		ResolveTests9.class,
 
 		NullAnnotationModelTests9.class,
+
+		JavaModelManagerTests.class,
 	};
 
 	Class[] deprecatedClasses = getDeprecatedJDOMTestClasses();
diff --git a/org.eclipse.jdt.core.tests.model/src/org/eclipse/jdt/core/tests/model/JavaModelManagerTests.java b/org.eclipse.jdt.core.tests.model/src/org/eclipse/jdt/core/tests/model/JavaModelManagerTests.java
new file mode 100644
index 0000000000..65b052db75
--- /dev/null
+++ b/org.eclipse.jdt.core.tests.model/src/org/eclipse/jdt/core/tests/model/JavaModelManagerTests.java
@@ -0,0 +1,176 @@
+package org.eclipse.jdt.core.tests.model;
+
+import java.util.ArrayList;
+import java.util.List;
+import java.util.concurrent.CountDownLatch;
+
+import org.eclipse.core.resources.IFile;
+import org.eclipse.core.resources.IMarker;
+import org.eclipse.core.resources.IProject;
+import org.eclipse.core.resources.IResource;
+import org.eclipse.core.resources.IncrementalProjectBuilder;
+import org.eclipse.core.resources.ResourcesPlugin;
+import org.eclipse.core.runtime.CoreException;
+import org.eclipse.core.runtime.IProgressMonitor;
+import org.eclipse.core.runtime.NullProgressMonitor;
+import org.eclipse.core.runtime.jobs.Job;
+import org.eclipse.jdt.core.IClassFile;
+import org.eclipse.jdt.core.IJavaProject;
+import org.eclipse.jdt.core.IOrdinaryClassFile;
+import org.eclipse.jdt.core.IPackageFragment;
+import org.eclipse.jdt.core.IPackageFragmentRoot;
+import org.eclipse.jdt.core.IType;
+import org.eclipse.jdt.internal.core.JavaElement;
+import org.eclipse.jdt.internal.core.nd.indexer.Indexer;
+
+public class JavaModelManagerTests extends AbstractJavaModelTests {
+
+	private static final IProgressMonitor NULL_MONITOR = new NullProgressMonitor();
+	private static final String PROJECT_NAME = JavaModelManagerTests.class.getSimpleName();
+
+	public JavaModelManagerTests(String name) {
+		super(name);
+	}
+
+	/**
+	 * Test for Bug 548456 - Concurrency problem with JavaModelManager and JavaElement.openWhenClosed()
+	 *
+	 * We create a project with a jar on its class path and ask after {@link JavaElement#exists()}
+	 * for a class in the jar. We do so from 2 different threads in parallel; with sufficient repetitions
+	 * we hope to run into the race condition described in the bug.
+	 */
+	public void testBug548456_concurrentElementInfoAccess() throws Exception {
+		int iterations = 20;
+		int numberOfThreads = 10;
+		for (int i = 0; i < iterations; ++i) {
+			doTestBug548456_concurrentCallBinaryTypeExists(numberOfThreads);
+		}
+	}
+
+	private void doTestBug548456_concurrentCallBinaryTypeExists(int numberOfThreads) throws Exception {
+		final IJavaProject project = setUpJavaProject(PROJECT_NAME);
+		try {
+			buildProject(project);
+			assertHasNoBuildProblems(project);
+
+			CountDownLatch latch = new CountDownLatch(numberOfThreads);
+			List<CheckIfTypeExists> runnables = new ArrayList<>(numberOfThreads);
+			for (int i = 0; i < numberOfThreads; ++i) {
+				CheckIfTypeExists runnable = new CheckIfTypeExists(project, latch);
+				runnables.add(runnable);
+			}
+
+			List<Thread> threads = startThreads(runnables);
+
+			boolean interrupted = false;
+			for (Thread thread : threads) {
+				try {
+					thread.join();
+				} catch (InterruptedException e) {
+					// we join all threads regardless of interruption, to be sure we don't leave running threads after this method done
+					interrupted = true;
+				}
+			}
+			assertFalse("waiting on test threads to finish must not be interrupted", interrupted);
+
+			for (CheckIfTypeExists runnable : runnables) {
+				assertTrue("expected type for test source to exist, despite concurrent access to JavaModelManager", runnable.typeExists);
+			}
+		} finally {
+			deleteProject(PROJECT_NAME);
+		}
+	}
+
+	private static List<Thread> startThreads(List<CheckIfTypeExists> runnables) {
+		List<Thread> threads = new ArrayList<>(runnables.size());
+		for (CheckIfTypeExists runnable : runnables) {
+			Thread thread = new Thread(runnable);
+			threads.add(thread);
+			thread.start();
+		}
+		return threads;
+	}
+
+	class CheckIfTypeExists implements Runnable {
+
+		private final IJavaProject project;
+		private final CountDownLatch latch;
+
+		boolean typeExists = false;
+
+		CheckIfTypeExists(IJavaProject project, CountDownLatch latch) {
+			this.project = project;
+			this.latch = latch;
+		}
+
+		@Override
+		public void run() {
+			IType type = retrieveTestType(this.project);
+			// we use a CountDownLatch to ensure the thread calls to IJavaElement.exists() are running as close together as possible
+			this.latch.countDown();
+			this.typeExists = type.exists();
+		}
+	}
+
+	static IType retrieveTestType(IJavaProject project) {
+		IFile jarResource = project.getProject().getFile("lib.jar");
+		IPackageFragmentRoot root = project.getPackageFragmentRoot(jarResource);
+		IPackageFragment packageFragment = root.getPackageFragment("p");
+		IClassFile classFile = packageFragment.getClassFile("X.class");
+		IOrdinaryClassFile ordinaryClassFile = (IOrdinaryClassFile) classFile;
+		IType type = ordinaryClassFile.getType();
+		return type;
+	}
+
+	private static void buildProject(IJavaProject javaProject) throws Exception {
+		IProject project = javaProject.getProject();
+		refreshProject(project);
+		project.build(IncrementalProjectBuilder.CLEAN_BUILD, NULL_MONITOR);
+		refreshProject(project);
+		project.build(IncrementalProjectBuilder.FULL_BUILD, NULL_MONITOR);
+		Job.getJobManager().join(ResourcesPlugin.FAMILY_MANUAL_BUILD, null);
+		Indexer.getInstance().waitForIndex(null);
+		refreshProject(project);
+	}
+
+	private static void refreshProject(IProject project) throws CoreException {
+		project.refreshLocal(IResource.DEPTH_INFINITE, NULL_MONITOR);
+		waitForManualRefresh();
+	}
+
+	private static void assertHasNoBuildProblems(IJavaProject javaProject) throws Exception {
+		IProject project = javaProject.getProject();
+		List<IMarker> modelProblems = getTestProjectErrorMarkers(project);
+		assertTrue("expected no problems when building, but got:" + System.lineSeparator() + toString(modelProblems),
+				modelProblems.isEmpty());
+	}
+
+	private static List<IMarker> getTestProjectErrorMarkers(IProject project) throws Exception {
+		IMarker[] problemMarkers = project.findMarkers(null, true, IResource.DEPTH_ZERO);
+		List<IMarker> errorMarkers = new ArrayList<>();
+		for (IMarker problemMarker : problemMarkers) {
+			int severity = problemMarker.getAttribute(IMarker.SEVERITY, IMarker.SEVERITY_INFO);
+			if (severity == IMarker.SEVERITY_ERROR) {
+				errorMarkers.add(problemMarker);
+			}
+		}
+		return errorMarkers;
+	}
+
+	private static String toString(List<IMarker> markers) throws Exception {
+		StringBuilder sb = new StringBuilder();
+		for (IMarker marker : markers) {
+			sb.append("Message: ");
+			sb.append((marker.getAttribute(IMarker.MESSAGE)));
+			sb.append(System.lineSeparator());
+			sb.append("Location: ");
+			sb.append(marker.getAttribute(IMarker.LOCATION));
+			sb.append(System.lineSeparator());
+			sb.append("Line: ");
+			sb.append(marker.getAttribute(IMarker.LINE_NUMBER));
+			sb.append(System.lineSeparator());
+		}
+		String fatalProblemsAsText = sb.toString();
+		return fatalProblemsAsText;
+	}
+}
diff --git a/org.eclipse.jdt.core.tests.model/workspace/JavaModelManagerTests/.classpath b/org.eclipse.jdt.core.tests.model/workspace/JavaModelManagerTests/.classpath
new file mode 100644
index 0000000000..068e11841f
--- /dev/null
+++ b/org.eclipse.jdt.core.tests.model/workspace/JavaModelManagerTests/.classpath
@@ -0,0 +1,7 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<classpath>
+    <classpathentry kind="src" path=""/>
+    <classpathentry kind="var" path="JCL_LIB" sourcepath="JCL_SRC" rootpath="JCL_SRCROOT"/>
+    <classpathentry kind="lib" path="lib.jar"/>
+    <classpathentry kind="output" path="bin"/>
+</classpath>
diff --git a/org.eclipse.jdt.core.tests.model/workspace/JavaModelManagerTests/.project b/org.eclipse.jdt.core.tests.model/workspace/JavaModelManagerTests/.project
new file mode 100644
index 0000000000..d277b7567a
--- /dev/null
+++ b/org.eclipse.jdt.core.tests.model/workspace/JavaModelManagerTests/.project
@@ -0,0 +1,17 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<projectDescription>
+	<name>JavaModelManagerTests</name>
+	<comment></comment>
+	<projects>
+	</projects>
+	<buildSpec>
+		<buildCommand>
+			<name>org.eclipse.jdt.core.javabuilder</name>
+			<arguments>
+			</arguments>
+		</buildCommand>
+	</buildSpec>
+	<natures>
+		<nature>org.eclipse.jdt.core.javanature</nature>
+	</natures>
+</projectDescription>
diff --git a/org.eclipse.jdt.core.tests.model/workspace/JavaModelManagerTests/lib.jar b/org.eclipse.jdt.core.tests.model/workspace/JavaModelManagerTests/lib.jar
new file mode 100644
index 0000000000..e2aadfd389
--- /dev/null
+++ b/org.eclipse.jdt.core.tests.model/workspace/JavaModelManagerTests/lib.jar
diff --git a/org.eclipse.jdt.core/model/org/eclipse/jdt/internal/core/JavaElement.java b/org.eclipse.jdt.core/model/org/eclipse/jdt/internal/core/JavaElement.java
index 9960576f8e..c43100b2cd 100644
--- a/org.eclipse.jdt.core/model/org/eclipse/jdt/internal/core/JavaElement.java
+++ b/org.eclipse.jdt.core/model/org/eclipse/jdt/internal/core/JavaElement.java
@@ -597,6 +597,13 @@ public abstract class JavaElement extends PlatformObject implements IJavaElement
 			if (info == null) {
 				info = newElements.get(this);
 			}
+			// Bug 548456: check if some concurrent call already added the info to the manager, do not throw an exception if so
+			if (info == null) {
+				info = manager.getInfo(this);
+				if (info != null) {
+					return info;
+				}
+			}
 			if (info == null) { // a source ref element could not be opened
 				// close the buffer that was opened for the openable parent
 			    // close only the openable's buffer (see https://bugs.eclipse.org/bugs/show_bug.cgi?id=62854)