Community
Participate
Working Groups
I have a project with a rather long classpath, more than 400 entries. When the debugger first stops at a breakpoint, it takes more than 30 seconds before it shows the source. I used visualvm to capture some thread dumps during that 30 seconds, and most of them look like this: "Worker-54" #503 prio=5 os_prio=0 tid=0x000000001a794800 nid=0x41ce4 runnable [0x00000000327de000] java.lang.Thread.State: RUNNABLE at java.io.WinNTFileSystem.getLastModifiedTime(Native Method) at java.io.File.lastModified(Unknown Source) at java.util.zip.ZipFile.<init>(Unknown Source) at java.util.zip.ZipFile.<init>(Unknown Source) at java.util.zip.ZipFile.<init>(Unknown Source) at org.eclipse.jdt.internal.core.JavaModelManager.getZipFile(JavaModelManager.java:2712) at org.eclipse.jdt.internal.core.util.Util.getJdkLevel(Util.java:846) at org.eclipse.jdt.internal.core.JarPackageFragmentRoot.<init>(JarPackageFragmentRoot.java:76) at org.eclipse.jdt.internal.core.JavaProject.getPackageFragmentRoot(JavaProject.java:1810) at org.eclipse.jdt.internal.core.JavaProject.computePackageFragmentRoots(JavaProject.java:615) at org.eclipse.jdt.internal.core.JavaProject.computePackageFragmentRoots(JavaProject.java:708) at org.eclipse.jdt.internal.core.JavaProject.computePackageFragmentRoots(JavaProject.java:672) at org.eclipse.jdt.internal.core.JavaProject.getAllPackageFragmentRoots(JavaProject.java:1430) at org.eclipse.jdt.internal.core.JavaProject.getAllPackageFragmentRoots(JavaProject.java:1425) at org.eclipse.jdt.internal.core.JavaProject.findPackageFragmentRoot0(JavaProject.java:1228) at org.eclipse.jdt.internal.core.JavaProject.findPackageFragmentRoot(JavaProject.java:1220) at org.eclipse.jdt.internal.launching.JavaSourceLookupUtil.getPackageFragmentRoot(JavaSourceLookupUtil.java:157) at org.eclipse.jdt.internal.launching.JavaSourceLookupUtil.translate(JavaSourceLookupUtil.java:57) at org.eclipse.jdt.launching.JavaRuntime.getSourceContainers(JavaRuntime.java:2449) at org.eclipse.jdt.launching.sourcelookup.containers.JavaSourcePathComputer.computeSourceContainers(JavaSourcePathComputer.java:58) at org.eclipse.debug.internal.core.sourcelookup.SourcePathComputer.computeSourceContainers(SourcePathComputer.java:71) at org.eclipse.debug.core.sourcelookup.containers.DefaultSourceContainer.createSourceContainers(DefaultSourceContainer.java:117) at org.eclipse.debug.core.sourcelookup.containers.CompositeSourceContainer.getSourceContainers(CompositeSourceContainer.java:133) - locked <0x00000000fa6ee7a8> (a org.eclipse.debug.core.sourcelookup.containers.DefaultSourceContainer) at org.eclipse.debug.core.sourcelookup.containers.CompositeSourceContainer.findSourceElements(CompositeSourceContainer.java:48) at org.eclipse.debug.core.sourcelookup.AbstractSourceLookupParticipant.findSourceElements(AbstractSourceLookupParticipant.java:70) at org.eclipse.debug.core.sourcelookup.AbstractSourceLookupDirector$SourceLookupQuery.run(AbstractSourceLookupDirector.java:142) at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42) at org.eclipse.debug.core.sourcelookup.AbstractSourceLookupDirector.doSourceLookup(AbstractSourceLookupDirector.java:505) at org.eclipse.debug.core.sourcelookup.AbstractSourceLookupDirector.getSourceElement(AbstractSourceLookupDirector.java:785) at org.eclipse.debug.internal.ui.sourcelookup.SourceLookupFacility.lookup(SourceLookupFacility.java:346) - locked <0x00000000ae4fd858> (a org.eclipse.debug.internal.ui.sourcelookup.SourceLookupFacility$LRU) at org.eclipse.debug.internal.ui.sourcelookup.SourceLookupFacility$SourceLookupJob.run(SourceLookupFacility.java:737) at org.eclipse.core.internal.jobs.Worker.run(Worker.java:54) When I do the exact same thing with the exact same project in eclipse 4.3.x, the source lookup takes just a second or so - very fast. I suspect the problem is in the JarPackageFragmentRoot constructor where it is calling Util.getJdkLevel -- it looks like older versions of JarPackageFragmentRoot didn't have that, but I'm just speculating -- I don't really know that much about it.
I am experiencing the same problem.
*** Bug 440517 has been marked as a duplicate of this bug. ***
looks like same as bug 439450 Lee, can you confirm if debugger is fast in projects without libs ?
I wonder why there has to be a zip file lookup in the first place. I believed the jar files would have been indexed anyway long before one starts to debug the code, so why would one want to do a lookup into the jar files now? Even if the source can be found in the source folders of the project and they are at the top of the build path...
Oh yeah, sorry I meant to say that, Yes indeed the debugger is fast on a project without libs. (In reply to Sarika Sinha from comment #3) > looks like same as bug 439450 > > Lee, can you confirm if debugger is fast in projects without libs ?
*** Bug 439450 has been marked as a duplicate of this bug. ***
I have the exact same problem on Centos 6. On big project the debug is very slow. On "normal" project the debug is very quick
No problem with 4.3, with 4.4 the debugger is extreme slow.
(In reply to t h from comment #8) > No problem with 4.3, with 4.4 the debugger is extreme slow. I wonder too, if bug 437193 was causing some of this slow-down. As part of the fix for that bug we got rid of one entire layer of (UI)Jobs.
(In reply to Michael Rennie from comment #9) > (In reply to t h from comment #8) > > No problem with 4.3, with 4.4 the debugger is extreme slow. > > I wonder too, if bug 437193 was causing some of this slow-down. As part of > the fix for that bug we got rid of one entire layer of (UI)Jobs. If so, we have to fix this in 4.4.x too.
I'm pretty sure the regression is due to the fix for bug 410207. Moving to JDT Core. Like every IJavaElement, JarPackageFragmentRoot is supposed to be a *handle*, i.e. it should be very lightweight and its creation should not depend on availability of the referenced element. The JarPackageFragmentRoot#complianceLevel field is unnecessary. This value should be computed in #computeChildren(..). I'm preparing a patch.
Is this the same performance regression that has been fixed via bug 441726?
Created attachment 246547 [details] Fix Looks like there's already a workaround for this regression in master, see bug 441726. I think the solution chosen in that bug is wrong. Having to maintain yet another cache is unnecessary and fragile. Here's a straightforward fix that just moves the computation of the complianceLevel back to where it should be. This patch needs to be tested with the scenarios of this bug, bug 410207, bug 441726, and their dups. After that, it needs to be backported to all branches that received bug 410207.
+1 to fix this in 4.4.1 and below.
I'm sorry the regression occurred in the first place, but how can moving initialization to a slightly later point help scenarios like refreshing the package explorer (bug 441726 comment 0)?
If the regression is caused by the bad fix for bug 410207, then it is my fault, sorry.
(In reply to Stephan Herrmann from comment #15) > but how can moving initialization to a slightly later point help scenarios > like refreshing the package explorer (bug 441726 comment 0)? It's all about the expected cost of operations: The expected cost of a handle creation is negligible. That's why we can create new JarPackageFragmentRoot objects all the time. On the other hand, we only call JarPackageFragmentRoot#computeChildren(..) when we're ready to pay the price for opening the JAR and reading its contents. The implementation of computeChildren(..) opens the ZipFile anyway (via getJar()), so the detection of the class file level is almost free there. The ZipFile is cached by the JavaModelManager. If everything works as it should, then the children of a JarPackageFragmentRoot should be cached in a JavaElementInfo (here: JavaProjectElementInfo) and should only be re-computed when the Jar has been touched or when the element info cache overflows.
I've verified that comment 13 fixes bug 441726. It brings that performance test back to 4.3.2 level, and it's a bit better than what's in master.
(In reply to Markus Keller from comment #17) Thanks for explaining!
(In reply to Markus Keller from comment #18) > I've verified that comment 13 fixes bug 441726. It brings that performance > test back to 4.3.2 level, and it's a bit better than what's in master. I verified that as well. Somehow when evaluating bug 441726, I convinced myself that object/handle creation and JarPackageFragmentRoot#computeChildren() invocations were on the order of 1:1. Before reading your explanation I reinvestigated and saw I was mistaken. I support rolling back that change and implementing this one. I also agree that having to maintain yet another cache is not good. My team has submitted several patches that fixed JDT caching problems, and we continue to find areas where caches are incorrectly evicted or underutilized. There appear to be too many caches, they are uncoordinated, and they are difficult to discover. I opened bug 442924, "Rationalize jar-related caches", where we can discuss the issue and try to make some progress.
Thanks for the confirmation, Terry. I agree the current caching strategies are not as clear as they could/should be. Re "who's to blame": I think pretty much everybody involved can take a share, yours truly included. I've verified that comment 13 still fixes bug 410207 as well. I've reverted bug 441726 and committed comment 13 in master: http://git.eclipse.org/c/jdt/eclipse.jdt.core.git/commit/?id=d35306cb5dcf7e4ac666fd0505f3086f50241fb2
Will this make it in time for 4.4.1?
(In reply to Gary D. Gregory from comment #22) > Will this make it in time for 4.4.1? Yes. N20140831-2000 already contains the fix. I'm running on that build now, and others could test it too (or test tomorrow's I-build). Jay, please review the fix for R4_4_maintenance and the other branches where bug 410207 was released.
Srikanth/Stephan, can you please review this for 4.4.1? I don't expect to be able to get to this today. TIA!
From looking at the code and reading comments here, I can confirm that http://git.eclipse.org/c/jdt/eclipse.jdt.core.git/commit/?id=d35306cb5dcf7e4ac666fd0505f3086f50241fb2 is a very straight-forward and clean improvement on top of bug 410207. I also checked that the sibling changes in PackageFragmentRoot and PackageFragmentRootInfo already perform their work during computeFolderChildren and computeFolderNonJavaResources, resp., good. I did not dive into details of why bug 441726 would be inferior, except for aspect of clarity of design. I also did not perform any performance measurements, trusting that comment 18 and comment 20 already sufficiently back this aspect. Under these reservations I'm in favor of back porting to 4.4.1 and below. BTW: I'm right now looking at poor performance of an Xtext-based tool, which is caused by this exact performance bug. As soon as we have a Luna-based build with this patch I can give it some real-world testing in that context.
(In reply to Stephan Herrmann from comment #25) > From looking at the code and reading comments here, I can confirm that > http://git.eclipse.org/c/jdt/eclipse.jdt.core.git/commit/ > ?id=d35306cb5dcf7e4ac666fd0505f3086f50241fb2 is a very straight-forward and > clean improvement on top of bug 410207. Thanks Stephan. I will release this for 4.4.1 in a bit.
(In reply to Jayaprakash Arthanareeswaran from comment #26) > Thanks Stephan. I will release this for 4.4.1 in a bit. It's here: http://git.eclipse.org/c/jdt/eclipse.jdt.core.git/commit/?h=R4_4_maintenance&id=5781fc0d3b262a5bc6ee6e12f16976ad6642c6ae Stephan, for the records, can you please grant the +1 for the review.
Resolving
(In reply to Markus Keller from comment #13) > it needs to be backported to all branches that received bug 410207.
(In reply to Jayaprakash Arthanareeswaran from comment #27) > Stephan, for the records, can you please grant the +1 for the review. sure
(In reply to Stephan Herrmann from comment #25) > BTW: I'm right now looking at poor performance of an Xtext-based tool, which > is caused by this exact performance bug. As soon as we have a Luna-based > build with this patch I can give it some real-world testing in that context. Quick test in the context of that Xtext-based tool: Using build M20140902-1430 a full build for one particular project went down from 6 min to 2 min. Great!
Siete penosi
Backported in R4_3_maintenance: http://git.eclipse.org/c/jdt/eclipse.jdt.core.git/commit/?h=R4_3_maintenance&id=4fcbe6b2b83836ba917473ab868964bb3274bf91 And R3_8_maintenance: http://git.eclipse.org/c/jdt/eclipse.jdt.core.git/commit/?h=R3_8_maintenance&id=aa07712f054e28ee243ed0acc633b38d78178dc7
And in R3_7_maintenance: http://git.eclipse.org/c/jdt/eclipse.jdt.core.git/commit/?h=R3_7_maintenance&id=cfc66021f700bf87dae5ce885c77781de04bcdf8 and in R3_6_maintenance_Java7: http://git.eclipse.org/c/jdt/eclipse.jdt.core.git/commit/?h=R3_6_maintenance_Java7&id=d945115702aaa61b428514d49a58fc83ca27c039 Tagged and maps files updated too.
As per comment #31, marking as verified.
*** Bug 443590 has been marked as a duplicate of this bug. ***
*** Bug 365394 has been marked as a duplicate of this bug. ***
*** Bug 524659 has been marked as a duplicate of this bug. ***
