Community
Participate
Working Groups
My workspace contains 70 large projects, each having WAS 6.0 on their classpath as a set of ~30 jars, total ~35MB. The workspace itself is ~150MB zipped up. The majority of the application is Java code, to be run on WAS 6.0. I have a tool that monitors how often zipfiles are opened. My workspace was building and after it read >2GB from the disk, I suspended the build at 70%. I noticed the following pattern for each of the WAS jars (all 30 were opened >1,000 times by JDT). During this build cycle, I saw the Java heap race from 600MB to 900MB, with GCs bring back the heap about every 2 seconds. So, we seem to generate ~150MB/s. Is there a way for JDT to cache the JDK level for a given jar on the classpath? Here is the identical pattern that was repeated some 30,000 times: Access pattern 1071/1071 for D:\WAS60\java\jre\lib\ext\dumpfmt.jar: _20_java.util.zip.ZipFile.<init>(ZipFile.java:322) _19_java.util.zip.ZipFile.<init>(ZipFile.java:392) _18_org.eclipse.jdt.internal.core.JavaModelManager.getZipFile(JavaModelManager.java:1751) _17_org.eclipse.jdt.internal.core.util.Util.getJdkLevel(Util.java:814) _16_org.eclipse.jdt.internal.core.ClasspathEntry.validateClasspathEntry(ClasspathEntry.java:1642) _15_org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath(JavaProject.java:2182) _14_org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath(JavaProject.java:2073) _13_org.eclipse.jdt.internal.core.DeltaProcessor.updateClasspathMarkers(DeltaProcessor.java:2107) _12_org.eclipse.jdt.internal.core.DeltaProcessor.updateClasspathMarkers(DeltaProcessor.java:2137) _11_org.eclipse.jdt.internal.core.DeltaProcessor.updateClasspathMarkers(DeltaProcessor.java:2153) _10_org.eclipse.jdt.internal.core.DeltaProcessor.resourceChanged(DeltaProcessor.java:1855) _9_org.eclipse.jdt.internal.core.DeltaProcessingState.resourceChanged(DeltaProcessingState.java:444) _8_org.eclipse.core.internal.events.NotificationManager$2.run(NotificationManager.java:280) _7_org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:37) _6_org.eclipse.core.internal.events.NotificationManager.notify(NotificationManager.java:274) _5_org.eclipse.core.internal.events.NotificationManager.broadcastChanges(NotificationManager.java:148) _4_org.eclipse.core.internal.resources.Workspace.broadcastBuildEvent(Workspace.java:240) _3_org.eclipse.core.internal.events.AutoBuildJob.doBuild(AutoBuildJob.java:142) _2_org.eclipse.core.internal.events.AutoBuildJob.run(AutoBuildJob.java:208) _1_org.eclipse.core.internal.jobs.Worker.run(Worker.java:58)
Please consider this bug for inclusion in the 3.2.2 maintenance stream.
Philippe, agree to set target to 3.2.2?
Chris, did you install 3.2.2 preview with fix for bug 159325 when you got this stack trace?
No :-) And I was told by Raj already that bug 159325 should fix this. I will try with the preview and reopen when necessary.
Reopen to set as duplicate (fixed means that something has been changed in the code , which is not the case...)
*** This bug has been marked as a duplicate of 159325 ***
Problem still remains when option for checking incompatible required libs is enabled. Original point for caching JDK level remains. Bug 159325 is about the fact that even when option was disabled, the zip opening still occurred in some cases.
That's right, but perhaps severity may be reduced? Chris, is it OK to set it to 'normal'?
Given bug 159325 got addressed, this is not longer as critical, since this situation cannot occur out of the box any longer. Still something to tackle in the near future.
CC'ed Gary our perf contact.
To be investigated during 3.3 M7
Created attachment 72665 [details] Untested patch... Jerome, I found a workspace related to this bug which contained several changes... I can't remember if they pass all tests, but I thought it could be interesting to use it as a starting point for a possible fix. HTH
Time permitting for 3.4
We ran out of time. Deferring post 3.4
Jay, please check if this is still an issue.
I still see JARs being opened multiple times for finding out the JDK level. I will see what can be done here.
When JavaCore.CORE_INCOMPATIBLE_JDK_LEVEL is set to WARNING or ERROR, the same JAR files are opened multiple times, which is resulting in avoidable I/O operations. Also, we can avoid opening more archives inside the method ClasspathEntry#validateLibraryContents. When I include both the changes I see some performance improvements. I will update after collecting some numbers.
Created attachment 198300 [details] Proposed patch This is a draft patch and may require some changes. But we can see some performance improvements with this. Here is the result without the fix and with fix respectively. The test scenario is restarting a workspace with 20 projects, each having the same 30 JAR files each of size 1.9 MB approx in the classpath. Without patch: ============== Used default compliance: 1.4 Scenario 'org.eclipse.jdt.core.tests.performance.FullSourceWorkspaceModelTests#testReopenMultipleProjects()' (average over 10 samples): Used Java Heap: 11.64M (95% in [10.92M, 12.36M]) Working Set: 69.2K (95% in [-25.5K, 163.9K]) Committed: 46K (95% in [-86.8K, 178.8K]) Working Set Peak: 0 (95% in [0, 0]) Elapsed Process: 20.65s (95% in [20.58s, 20.72s]) Kernel time: 2.56s (95% in [2.49s, 2.63s]) Page Faults: 218 (95% in [166, 269]) CPU Time: 4.66s (95% in [4.59s, 4.73s]) GDI Objects: 0 (95% in [0, 0]) Open Handles: 0 (95% in [0, 0]) Read Count: 4.06K (95% in [4.02K, 4.1K]) Bytes Read: 3.02M (95% in [731.22K, 5.33M]) With patch ========== Used default compliance: 1.4 Scenario 'org.eclipse.jdt.core.tests.performance.FullSourceWorkspaceModelTests#testReopenMultipleProjects()' (average over 10 samples): Used Java Heap: 12.76M (95% in [12.74M, 12.79M]) Working Set: 94K (95% in [-92.61K, 280.61K]) Committed: 82K (95% in [-158.41K, 322.41K]) Working Set Peak: 0 (95% in [0, 0]) Elapsed Process: 20.72s (95% in [20.66s, 20.77s]) Kernel time: 2.59s (95% in [2.49s, 2.69s]) Page Faults: 243 (95% in [180, 306]) CPU Time: 4.74s (95% in [4.66s, 4.82s]) GDI Objects: 0 (95% in [0, 0]) Open Handles: 0 (95% in [0, 0]) Read Count: 4.05K (95% in [4.04K, 4.06K]) Bytes Read: 2M (95% in [1.89M, 2.11M])
Satyam, I see the improvement in Bytes Read. Do you think it's significant enough?
When I ran the tests for isolated classpath validation, the difference in performance numbers is much more stark. The too-good-to-believe numbers with the patch can be attributed to the fact that the test runs do not require to open the JAR files since the information they need has already been cached. Nevertheless, the improvement is good. ============= With HEAD ============= Used default compliance: 1.4 Scenario 'org.eclipse.jdt.core.tests.performance.FullSourceWorkspaceModelTests#testReopenMultipleProjects()' (average over 10 samples): Used Java Heap: 93.79K (95% in [93.2K, 94.38K]) Working Set: -146K (95% in [-165.09K, -126.91K]) Committed: -139.2K (95% in [-210.96K, -67.44K]) Working Set Peak: 0 (95% in [0, 0]) Elapsed Process: 58.91s (95% in [58.65s, 59.18s]) Kernel time: 31.72s (95% in [31.22s, 32.21s]) Page Faults: 1.54M (95% in [1.5M, 1.58M]) CPU Time: 55.62s (95% in [55.37s, 55.87s]) GDI Objects: 0 (95% in [0, 0]) Open Handles: 0 (95% in [0, 0]) Read Count: 82.04K (95% in [82.03K, 82.04K]) Bytes Read: 5.68G (95% in [5.68G, 5.68G]) ------------------------------------- Model performance test statistics: ------------------------------------- ============= With Patch ============= Used default compliance: 1.4 Scenario 'org.eclipse.jdt.core.tests.performance.FullSourceWorkspaceModelTests#testReopenMultipleProjects()' (average over 10 samples): Used Java Heap: 381.85K (95% in [369.46K, 394.24K]) Working Set: 819 (95% in [-1.01K, 2.61K]) Committed: 4.8K (95% in [-11.38K, 20.98K]) Working Set Peak: 0 (95% in [0, 0]) Elapsed Process: 268ms (95% in [264ms, 273ms]) Kernel time: 0ms (95% in [0ms, 0ms]) Page Faults: 22 (95% in [21, 22]) CPU Time: 268ms (95% in [264ms, 273ms]) GDI Objects: 0 (95% in [0, 0]) Open Handles: 0 (95% in [0, 0]) Read Count: 4 (95% in [-5, 14]) Bytes Read: 2.81K (95% in [-3.55K, 9.18K]) ------------------------------------- Model performance test statistics: -------------------------------------
This bug hasn't had any activity in quite some time. Maybe the problem got resolved, was a duplicate of something else, or became less pressing for some reason - or maybe it's still relevant but just hasn't been looked at yet. If you have further information on the current state of the bug, please add it. The information can be, for example, that the problem still occurs, that you still want the feature, that more information is needed, or that the bug is (for whatever reason) no longer relevant. -- The automated Eclipse Genie.
