Bug 571340 - [performance] Improve "Updating plug-in dependencies" jar validation
Summary: [performance] Improve "Updating plug-in dependencies" jar validation
Status: VERIFIED FIXED
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Core (show other bugs)
Version: 4.20   Edit
Hardware: All All
: P3 enhancement (vote)
Target Milestone: 4.21 M3   Edit
Assignee: Jörg Kubitz CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks: 568157
  Show dependency tree
 
Reported: 2021-02-19 05:41 EST by Jörg Kubitz CLA
Modified: 2021-10-27 07:37 EDT (History)
2 users (show)

See Also:


Attachments
Screenshot VisualVM_Updating plug-in dependencies_20210816.png (116.15 KB, image/png)
2021-08-16 05:48 EDT, Jörg Kubitz CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Jörg Kubitz CLA 2021-02-19 05:41:08 EST
This is a copy of bug 570904 for PDE:

When i touch the build.properties file in a plugin then eclipse takes a minute to "Updating plug-in dependencies" in a big workspace (> 500 Projects with > 2500 .jar).
As far as i have sampled there is one reason left why it takes so long:

Eclipse reads every dependend .jar file. This currently happens in JavaModelManager.verifyArchiveContent(IPath) calling getZipFile.
Even though the jar files have not been changed. Thousends in my case.

When a single JAR is added to a Project it is opened up in JDT to 4 times:
1. synchronous JavaModelManager.verifyArchiveContent
   to check wether its a valid Jar
2. async ResourceChangeEvent -> JavaModelManager.verifyArchiveContent
   to check wether its a valid Jar (this was already done!)
3. async IndexManager -> AddJarFileToIndex.execute
   to index all filenames within and extract "module-info" file
4. async IndexManager -> AutomaticModuleNaming.determineAutomaticModuleName
   to extract "Automatic-Module-Name" 
see Stacktraces below.

"// TODO (kent) we could just remove the in-memory index and have the indexing check for timestamps" (ClasspathChange:534)

My plan is to validate the jar archive only once synchronous and renember that state ~somewhere~. By now i have not found the right spot whether that should be in a IFileState, IFileStore, IFileInfo (like lastModified) , the workspace (may affect multiple resources when aliased) ResourceInfo (like modStamp) , inside JDT, or a generalized ZIP cache (together with bug 571307).

Ideas / Suggestions welcome!


Stacktraces:

Thread [main] (Suspended (breakpoint at line 228 in ZipFile))	
	owns: RunnableLock  (id=1161)	
	ZipFile.<init>(File) line: 191	
	JavaModelManager.getZipFile(IPath, boolean) line: 2937	
	JavaModelManager.getZipFile(IPath) line: 2906	
	JavaModelManager.verifyArchiveContent(IPath) line: 2887	
	ClasspathEntry.validateLibraryContents(IPath, IJavaProject, String) line: 2533	
	ClasspathEntry.validateLibraryEntry(IPath, IJavaProject, String, IPath, String, boolean) line: 2459	
	ClasspathEntry.validateClasspathEntry(IJavaProject, IClasspathEntry, IClasspathContainer, boolean, boolean) line: 2322	
	ClasspathEntry.validateClasspathEntry(IJavaProject, IClasspathEntry, boolean, boolean) line: 2193	
	ClasspathValidation.validate() line: 75	
	SetClasspathOperation(ChangeClasspathOperation).classpathChanged(ClasspathChange, boolean) line: 55	
	SetClasspathOperation.executeOperation() line: 78	
	SetClasspathOperation(JavaModelOperation).run(IProgressMonitor) line: 740	
	Workspace.run(ICoreRunnable, ISchedulingRule, int, IProgressMonitor) line: 2292	
	Workspace.run(IWorkspaceRunnable, ISchedulingRule, int, IProgressMonitor) line: 2317	
	SetClasspathOperation(JavaModelOperation).runOperation(IProgressMonitor) line: 811	
	JavaProject.setRawClasspath(IClasspathEntry[], IClasspathEntry[], IPath, boolean, IProgressMonitor) line: 3608	
	JavaProject.setRawClasspath(IClasspathEntry[], IPath, boolean, IProgressMonitor) line: 3568	
	JavaProject.setRawClasspath(IClasspathEntry[], IProgressMonitor) line: 3624	
	ClasspathTests(AbstractJavaModelTests).setClasspath(IJavaProject, IClasspathEntry[]) line: 3102	
	ClasspathTests.testBug229042() line: 6920	

Thread [Worker-12: Building] (Suspended (breakpoint at line 228 in ZipFile))	
	ZipFile.<init>(File) line: 191	
	JavaModelManager.getZipFile(IPath, boolean) line: 2937	
	JavaModelManager.getZipFile(IPath) line: 2906	
	JavaModelManager.verifyArchiveContent(IPath) line: 2887	
	ClasspathEntry.validateLibraryContents(IPath, IJavaProject, String) line: 2533	
	ClasspathEntry.validateLibraryEntry(IPath, IJavaProject, String, IPath, String, boolean) line: 2459	
	ClasspathEntry.validateClasspathEntry(IJavaProject, IClasspathEntry, IClasspathContainer, boolean, boolean) line: 2322	
	ClasspathEntry.validateClasspathEntry(IJavaProject, IClasspathEntry, boolean, boolean) line: 2193	
	ClasspathValidation.validate() line: 75	
	DeltaProcessor.resourceChanged(IResourceChangeEvent) line: 2199	
	DeltaProcessingState.resourceChanged(IResourceChangeEvent) line: 477	
	NotificationManager$1.run() line: 305	
	SafeRunner.run(ISafeRunnable) line: 45	
	NotificationManager.notify(ResourceChangeListenerList$ListenerEntry[], ResourceChangeEvent, boolean) line: 295	
	NotificationManager.broadcastChanges(ElementTree, ResourceChangeEvent, boolean) line: 158	
	Workspace.broadcastBuildEvent(Object, int, int) line: 366	
	AutoBuildJob.doBuild(IProgressMonitor) line: 150	
	AutoBuildJob.run(IProgressMonitor) line: 244	
	Worker.run() line: 63	

Daemon Thread [Java indexing] (Suspended (breakpoint at line 228 in ZipFile))	
	ZipFile.<init>(File) line: 191	
	AddJarFileToIndex.execute(IProgressMonitor) line: 150	
	IndexManager(JobManager).run() line: 414	
	Thread.run() line: 834	

Daemon Thread [Java indexing] (Suspended (breakpoint at line 228 in ZipFile))	
	JarFile(ZipFile).<init>(File, int, Charset) line: 228	
	JarFile(ZipFile).<init>(File, int) line: 177	
	JarFile.<init>(File, boolean, int, Runtime$Version) line: 348	
	JarFile.<init>(File, boolean, int) line: 319	
	JarFile.<init>(String) line: 258	
	AutomaticModuleNaming.determineAutomaticModuleName(String) line: 33	
	AddJarFileToIndex.execute(IProgressMonitor) line: 252	
	IndexManager(JobManager).run() line: 414	
	Thread.run() line: 834
Comment 1 Jörg Kubitz CLA 2021-03-07 08:21:06 EST
All those threads could use the already existing cache
 ThreadLocal<ZipCache> useJavaModelManager.zipFiles
but 1. its ThreadLocal and 2. needs to be initialized with 
 JavaModelManager.cacheZipFiles()

I dont get why its Threadlocal since a ZipFile itself is well synchronized.
Make ZipCache.map a ConcurrentHashmap and avoid Threadlocal?
Comment 2 Eclipse Genie CLA 2021-06-28 05:58:56 EDT
New Gerrit change created: https://git.eclipse.org/r/c/jdt/eclipse.jdt.core/+/182516
Comment 4 Andrey Loskutov CLA 2021-08-16 03:58:26 EDT
Jörg, do you plan to provide further fixes? I
f not, please verify if the patch works as expected with latest nightly build and resolve this issue.
Comment 5 Jörg Kubitz CLA 2021-08-16 05:44:51 EDT
(In reply to Andrey Loskutov from comment #4)
> Jörg, do you plan to provide further fixes? I
> f not, please verify if the patch works as expected with latest nightly
> build and resolve this issue.

I ran a test today with/without the patch. This patch reduced the time for "Updating plug-in dependencies" from 21 to 17 sec. Its better but far away from good.
10 of that 17 sec have been used in JavadocLocationManager.getJavadocLocation:

CoreUtility.jarContainsResource(File, String, boolean) line: 235	
JavadocLocationManager.getJavadocLocation(IPluginModelBase) line: 47	
PDEClasspathContainer.getClasspathAttributes(IPluginModelBase) line: 157	
PDEClasspathContainer.addExternalPlugin(IPluginModelBase, Rule[], ArrayList<IClasspathEntry>) line: 84	
RequiredPluginsClasspathContainer.addPlugin(BundleDescription, boolean, Map<BundleDescription,ArrayList<Rule>>, ArrayList<IClasspathEntry>) line: 352	
RequiredPluginsClasspathContainer.addDependency(BundleDescription, HashSet<BundleDescription>, Map<BundleDescription,ArrayList<Rule>>, ArrayList<IClasspathEntry>, boolean) line: 297	
RequiredPluginsClasspathContainer.addDependency(BundleDescription, HashSet<BundleDescription>, Map<BundleDescription,ArrayList<Rule>>, ArrayList<IClasspathEntry>, boolean) line: 309	
RequiredPluginsClasspathContainer.addDependency(BundleDescription, HashSet<BundleDescription>, Map<BundleDescription,ArrayList<Rule>>, ArrayList<IClasspathEntry>, boolean) line: 309	
RequiredPluginsClasspathContainer.addDependency(BundleDescription, HashSet<BundleDescription>, Map<BundleDescription,ArrayList<Rule>>, ArrayList<IClasspathEntry>, boolean) line: 309	
RequiredPluginsClasspathContainer.addDependency(BundleDescription, HashSet<BundleDescription>, Map<BundleDescription,ArrayList<Rule>>, ArrayList<IClasspathEntry>) line: 280	
RequiredPluginsClasspathContainer.computePluginEntries() line: 162	
RequiredPluginsClasspathContainer.getClasspathEntries() line: 112	
ClasspathEntry.validateClasspathEntry(IJavaProject, IClasspathEntry, IClasspathContainer, boolean, boolean) line: 2252	
ClasspathEntry.validateClasspathEntry(IJavaProject, IClasspathEntry, boolean, boolean) line: 2193	
ClasspathValidation.validate() line: 75	
SetContainerOperation(ChangeClasspathOperation).classpathChanged(ClasspathChange, boolean) line: 55	
SetContainerOperation.executeOperation() line: 117	
SetContainerOperation(JavaModelOperation).run(IProgressMonitor) line: 740	
Workspace.run(ICoreRunnable, ISchedulingRule, int, IProgressMonitor) line: 2313	
Workspace.run(IWorkspaceRunnable, ISchedulingRule, int, IProgressMonitor) line: 2338	
SetContainerOperation(JavaModelOperation).runOperation(IProgressMonitor) line: 811	
JavaCore.setClasspathContainer(IPath, IJavaProject[], IClasspathContainer[], IProgressMonitor) line: 5977	
PluginModelManager$UpdateClasspathsJob.run(IProgressMonitor) line: 104	
Worker.run() line: 63	

One should be able to cache that aswell (jar has not changed=> javadoc location is still the same). Unfortunatly i do not have time for further improvements.
Comment 6 Jörg Kubitz CLA 2021-08-16 05:48:04 EDT
Created attachment 286950 [details]
Screenshot VisualVM_Updating plug-in dependencies_20210816.png

Added screenshot of current sampling
Comment 7 Jay Arthanareeswaran CLA 2021-08-19 06:39:45 EDT
Verified for 4.21 M3 by code inspection.