Community
Participate
Working Groups
We are a large adopting product. This is the scenario that has regressed for us: 1) As root, modify our product by adding or removing a feature. 2) As a non-root user, start the product. For our product that is built on 3.6.1, step 2 takes 5.5 minutes (which is already very bad), but for our product that is built on 3.6.2, step 2 takes 23.5 minutes. I have some Yourkit profiles for step 2, which I can send to you. We see that this method is very expensive: org.eclipse.equinox.internal.p2.metadata.repository.io.MetadataWriter.writeInstallableUnit(IInstallableUnit)
These are the "p2" plug-ins, in our current drivers: org.eclipse.equinox.p2.artifact.repository,1.1.1.R36x_v20100901,../SDPShared/plugins/org.eclipse.equinox.p2.artifact.repository_1.1.1.R36x_v20100901.jar,4,false org.eclipse.equinox.p2.artifact.repository.nl1,1.1.1.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.artifact.repository.nl1_1.1.1.v201102031400.jar,4,false org.eclipse.equinox.p2.console,1.0.200.v20100601,../SDPShared/plugins/org.eclipse.equinox.p2.console_1.0.200.v20100601.jar,4,false org.eclipse.equinox.p2.console.nl1,1.0.200.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.console.nl1_1.0.200.v201102031400.jar,4,false org.eclipse.equinox.p2.core,2.0.3.R36x_v20110111,../SDPShared/plugins/org.eclipse.equinox.p2.core_2.0.3.R36x_v20110111.jar,4,false org.eclipse.equinox.p2.core.nl1,2.0.3.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.core.nl1_2.0.3.v201102031400.jar,4,false org.eclipse.equinox.p2.director,2.0.3.R36x_v20101117-1018,../SDPShared/plugins/org.eclipse.equinox.p2.director_2.0.3.R36x_v20101117-1018.jar,4,false org.eclipse.equinox.p2.director.app,1.0.201.R36x_v20100823,../SDPShared/plugins/org.eclipse.equinox.p2.director.app_1.0.201.R36x_v20100823.jar,4,false org.eclipse.equinox.p2.director.app.nl1,1.0.201.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.director.app.nl1_1.0.201.v201102031400.jar,4,false org.eclipse.equinox.p2.director.nl1,2.0.3.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.director.nl1_2.0.3.v201102031400.jar,4,false org.eclipse.equinox.p2.directorywatcher,1.0.203.R36x_v20101220,../SDPShared/plugins/org.eclipse.equinox.p2.directorywatcher_1.0.203.R36x_v20101220.jar,4,false org.eclipse.equinox.p2.directorywatcher.nl1,1.0.203.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.directorywatcher.nl1_1.0.203.v201102031400.jar,4,false org.eclipse.equinox.p2.engine,2.0.0.v20100606,../SDPShared/plugins/org.eclipse.equinox.p2.engine_2.0.0.v20100606.jar,4,false org.eclipse.equinox.p2.engine.nl1,2.0.0.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.engine.nl1_2.0.0.v201102031400.jar,4,false org.eclipse.equinox.p2.extensionlocation,1.2.0.v20100518,../SDPShared/plugins/org.eclipse.equinox.p2.extensionlocation_1.2.0.v20100518.jar,4,false org.eclipse.equinox.p2.extensionlocation.nl1,1.2.0.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.extensionlocation.nl1_1.2.0.v201102031400.jar,4,false org.eclipse.equinox.p2.garbagecollector,1.0.100.v20100503,../SDPShared/plugins/org.eclipse.equinox.p2.garbagecollector_1.0.100.v20100503.jar,4,false org.eclipse.equinox.p2.garbagecollector.nl1,1.0.100.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.garbagecollector.nl1_1.0.100.v201102031400.jar,4,false org.eclipse.equinox.p2.jarprocessor,1.0.200.v20100503a,../SDPShared/plugins/org.eclipse.equinox.p2.jarprocessor_1.0.200.v20100503a.jar,4,false org.eclipse.equinox.p2.jarprocessor.nl1,1.0.200.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.jarprocessor.nl1_1.0.200.v201102031400.jar,4,false org.eclipse.equinox.p2.metadata,2.0.1.R36x_v20101202,../SDPShared/plugins/org.eclipse.equinox.p2.metadata_2.0.1.R36x_v20101202.jar,4,false org.eclipse.equinox.p2.metadata.generator,1.0.202.R36x_v20101208-1400,../SDPShared/plugins/org.eclipse.equinox.p2.metadata.generator_1.0.202.R36x_v20101208-1400.jar,4,false org.eclipse.equinox.p2.metadata.generator.nl1,1.0.202.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.metadata.generator.nl1_1.0.202.v201102031400.jar,4,false org.eclipse.equinox.p2.metadata.nl1,2.0.1.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.metadata.nl1_2.0.1.v201102031400.jar,4,false org.eclipse.equinox.p2.metadata.repository,1.1.0.v20100513,../SDPShared/plugins/org.eclipse.equinox.p2.metadata.repository_1.1.0.v20100513.jar,4,false org.eclipse.equinox.p2.metadata.repository.nl1,1.1.0.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.metadata.repository.nl1_1.1.0.v201102031400.jar,4,false org.eclipse.equinox.p2.operations,2.0.0.v20100510,../SDPShared/plugins/org.eclipse.equinox.p2.operations_2.0.0.v20100510.jar,4,false org.eclipse.equinox.p2.operations.nl1,2.0.0.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.operations.nl1_2.0.0.v201102031400.jar,4,false org.eclipse.equinox.p2.publisher,1.1.2.v20100824-2220,../SDPShared/plugins/org.eclipse.equinox.p2.publisher_1.1.2.v20100824-2220.jar,4,false org.eclipse.equinox.p2.publisher.nl1,1.1.2.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.publisher.nl1_1.1.2.v201102031400.jar,4,false org.eclipse.equinox.p2.ql,2.0.0.v20100503a,../SDPShared/plugins/org.eclipse.equinox.p2.ql_2.0.0.v20100503a.jar,4,false org.eclipse.equinox.p2.ql.nl1,2.0.0.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.ql.nl1_2.0.0.v201102031400.jar,4,false org.eclipse.equinox.p2.reconciler.dropins,1.1.2.R36x_v20110114,../SDPShared/plugins/org.eclipse.equinox.p2.reconciler.dropins_1.1.2.R36x_v20110114.jar,4,true org.eclipse.equinox.p2.reconciler.dropins.nl1,1.1.2.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.reconciler.dropins.nl1_1.1.2.v201102031400.jar,4,false org.eclipse.equinox.p2.repository,2.0.2.R36x_v20110111-1500,../SDPShared/plugins/org.eclipse.equinox.p2.repository_2.0.2.R36x_v20110111-1500.jar,4,false org.eclipse.equinox.p2.repository.nl1,2.0.2.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.repository.nl1_2.0.2.v201102031400.jar,4,false org.eclipse.equinox.p2.repository.tools,2.0.1.R36x_v20100823,../SDPShared/plugins/org.eclipse.equinox.p2.repository.tools_2.0.1.R36x_v20100823.jar,4,false org.eclipse.equinox.p2.repository.tools.nl1,2.0.1.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.repository.tools.nl1_2.0.1.v201102031400.jar,4,false org.eclipse.equinox.p2.touchpoint.eclipse,2.0.3.R36x_v20101202,../SDPShared/plugins/org.eclipse.equinox.p2.touchpoint.eclipse_2.0.3.R36x_v20101202.jar,4,false org.eclipse.equinox.p2.touchpoint.eclipse.nl1,2.0.3.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.touchpoint.eclipse.nl1_2.0.3.v201102031400.jar,4,false org.eclipse.equinox.p2.touchpoint.natives,1.0.201.R36x_v20110111,../SDPShared/plugins/org.eclipse.equinox.p2.touchpoint.natives_1.0.201.R36x_v20110111.jar,4,false org.eclipse.equinox.p2.touchpoint.natives.nl1,1.0.201.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.touchpoint.natives.nl1_1.0.201.v201102031400.jar,4,false org.eclipse.equinox.p2.ui,2.0.0.v20100518,../SDPShared/plugins/org.eclipse.equinox.p2.ui_2.0.0.v20100518.jar,4,false org.eclipse.equinox.p2.ui.nl1,2.0.0.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.ui.nl1_2.0.0.v201102031400.jar,4,false org.eclipse.equinox.p2.ui.sdk,1.0.100.v20100513,../SDPShared/plugins/org.eclipse.equinox.p2.ui.sdk_1.0.100.v20100513.jar,4,false org.eclipse.equinox.p2.ui.sdk.nl1,1.0.100.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.ui.sdk.nl1_1.0.100.v201102031400.jar,4,false org.eclipse.equinox.p2.ui.sdk.scheduler,1.0.0.v20100507-1815,../SDPShared/plugins/org.eclipse.equinox.p2.ui.sdk.scheduler_1.0.0.v20100507-1815.jar,4,false org.eclipse.equinox.p2.ui.sdk.scheduler.nl1,1.0.0.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.ui.sdk.scheduler.nl1_1.0.0.v201102031400.jar,4,false org.eclipse.equinox.p2.updatechecker,1.1.101.R36x_v20100823,../SDPShared/plugins/org.eclipse.equinox.p2.updatechecker_1.1.101.R36x_v20100823.jar,4,false org.eclipse.equinox.p2.updatechecker.nl1,1.1.101.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.updatechecker.nl1_1.1.101.v201102031400.jar,4,false org.eclipse.equinox.p2.updatesite,1.0.201.R36x_v20100823,../SDPShared/plugins/org.eclipse.equinox.p2.updatesite_1.0.201.R36x_v20100823.jar,4,false org.eclipse.equinox.p2.updatesite.nl1,1.0.201.v201102031400,../SDPShared/plugins/org.eclipse.equinox.p2.updatesite.nl1_1.0.201.v201102031400.jar,4,false
Created attachment 188821 [details] Sampling profile taken during the first 10 minutes of startup
Created attachment 188822 [details] Tracing profile, about a minute long, taken at 15 minute mark
Created attachment 188823 [details] Sampling profile taken during the first 10 minutes of startup
Are you sure that in both case the number of plugins installed as root is the same. Moving to DJ since I don't have access to the data set.
(In reply to comment #5) > Are you sure that in both case the number of plugins installed as root is the > same. I counted the number of lines in bundles.info: Previous product: 3,529 Current product: 3,345
This is very strange as the code isn't doing anything unusual and hasn't changed since before Eclipse 3.6.
Created attachment 188993 [details] p2 bunldes from the "previous" version of our product
(In reply to comment #7) > This is very strange as the code isn't doing anything unusual and hasn't > changed since before Eclipse 3.6. I atatched the list of p2 bundles from the previous version of our product, so that you could see what has changed wrt the current version.
Although the specific "write out the IUs" code didn't change, I was reminded that there was code changed in 3.6.2 w.r.t. sharing IUs and String interning.
Here is a report that shows the differences between the p2 plug-ins (I filtered out the NL ones) between the two versions of our product. Comparison of C:\Documents and Settings\karasiuk\curr-p2-no-nl.txt and C:\Documents and Settings\karasiuk\prev-p2-no-nl.txt 2/15/2011 9:29:58 AM Mode: Just Differences ----------------------------------------------------- L3 org.eclipse.equinox.p2.core,2.0.3.R36x_v20110111,../SDPShared/plugins/org.eclipse.equinox.p2.core_2.0.3.R36x_v20110111.jar,4,false org.eclipse.equinox.p2.director,2.0.3.R36x_v20101117-1018,../SDPShared/plugins/org.eclipse.equinox.p2.director_2.0.3.R36x_v20101117-1018.jar,4,false R3 org.eclipse.equinox.p2.core,2.0.2.R36x_v20100804,../SDPShared/plugins/org.eclipse.equinox.p2.core_2.0.2.R36x_v20100804.jar,4,false org.eclipse.equinox.p2.director,2.0.2.R36x_v20100823,../SDPShared/plugins/org.eclipse.equinox.p2.director_2.0.2.R36x_v20100823.jar,4,false ----------------------------------------------------- L6 org.eclipse.equinox.p2.directorywatcher,1.0.203.R36x_v20101220,../SDPShared/plugins/org.eclipse.equinox.p2.directorywatcher_1.0.203.R36x_v20101220.jar,4,false R6 org.eclipse.equinox.p2.directorywatcher,1.0.202.R36x_v20100727,../SDPShared/plugins/org.eclipse.equinox.p2.directorywatcher_1.0.202.R36x_v20100727.jar,4,false ----------------------------------------------------- L11 org.eclipse.equinox.p2.metadata,2.0.1.R36x_v20101202,../SDPShared/plugins/org.eclipse.equinox.p2.metadata_2.0.1.R36x_v20101202.jar,4,false org.eclipse.equinox.p2.metadata.generator,1.0.202.R36x_v20101208-1400,../SDPShared/plugins/org.eclipse.equinox.p2.metadata.generator_1.0.202.R36x_v20101208-1400.jar,4,false R11 org.eclipse.equinox.p2.metadata,2.0.0.v20100601,../SDPShared/plugins/org.eclipse.equinox.p2.metadata_2.0.0.v20100601.jar,4,false org.eclipse.equinox.p2.metadata.generator,1.0.200.v20100503a,../SDPShared/plugins/org.eclipse.equinox.p2.metadata.generator_1.0.200.v20100503a.jar,4,false ----------------------------------------------------- L17 org.eclipse.equinox.p2.reconciler.dropins,1.1.2.R36x_v20110114,../SDPShared/plugins/org.eclipse.equinox.p2.reconciler.dropins_1.1.2.R36x_v20110114.jar,4,true org.eclipse.equinox.p2.repository,2.0.2.R36x_v20110111-1500,../SDPShared/plugins/org.eclipse.equinox.p2.repository_2.0.2.R36x_v20110111-1500.jar,4,false R17 org.eclipse.equinox.p2.reconciler.dropins,1.1.1.R36x_v20100929,../SDPShared/plugins/org.eclipse.equinox.p2.reconciler.dropins_1.1.1.R36x_v20100929.jar,4,true org.eclipse.equinox.p2.repository,2.0.1.R36x_v20100823,../SDPShared/plugins/org.eclipse.equinox.p2.repository_2.0.1.R36x_v20100823.jar,4,false ----------------------------------------------------- L20 org.eclipse.equinox.p2.touchpoint.eclipse,2.0.3.R36x_v20101202,../SDPShared/plugins/org.eclipse.equinox.p2.touchpoint.eclipse_2.0.3.R36x_v20101202.jar,4,false org.eclipse.equinox.p2.touchpoint.natives,1.0.201.R36x_v20110111,../SDPShared/plugins/org.eclipse.equinox.p2.touchpoint.natives_1.0.201.R36x_v20110111.jar,4,false R20 org.eclipse.equinox.p2.touchpoint.eclipse,2.0.2.R36x_v20100823,../SDPShared/plugins/org.eclipse.equinox.p2.touchpoint.eclipse_2.0.2.R36x_v20100823.jar,4,false org.eclipse.equinox.p2.touchpoint.natives,1.0.200.v20100503a,../SDPShared/plugins/org.eclipse.equinox.p2.touchpoint.natives_1.0.200.v20100503a.jar,4,false
To provide an update here, the problem was only reproducible on Gary's machine and using his old .eclipse folder (which had several other older product installs). Unfortunately he is now in a state where he can't reproduce the problem any longer. I think a yourkit profile from the full operation might be useful if we can get back into that state. If anyone else has suggestions on what else to investigate, please add a comment.
Closing as wontfix until further notice.
For closure here, we were able to find another machine which would reproduce the same problem (with a slightly larger data set). After some investigation we believe that it is caused by bug 338599. In my case I had a 27M content.xml file (several thousand features and bundles that had been installed via the drop-ins) and we were parsing that file, modifying it, and then re-writing it several thousand times without need. Test teams are currently testing the fix to see if it was indeed the cause.
Created attachment 190168 [details] screenshot of profiled data This screenshot is from the "10 minute" profile that I attached. It shows where most of the time is being spent. I don't know the code, but from the method names, it sounds like this code is involved with processing features and writing stuff out.
This is similar to the stack that I saw when I am able to profile the whole operation in the "bad" case. Just to confirm, this is when you're running with the hacked JAR? The code in that stack (LocalMetadataRepository#addReferences) is exactly the code that we modified so I would hope not to see it here. (my local profile snapshots after the new JAR look a lot different than before)
Created attachment 190171 [details] Screenshot from the 1 minute profile The earlier screenshot, shows things at a "macro" level, and identifies the time being spent in this method: org.eclipse.equinox.internal.p2.metadata.repository.io.MetadataWriter.writeInstallableUnit(IInstallableUnit) This new screenshot is from the tracing profile, and still shows the time being spent in the writeInstallableUnit(IInstallableUnit) method but now has the extra detail of showing invocation counts, and the fan out that happens with this method. Is this consistent with the problem that you fixed?
Created attachment 190176 [details] profile snapshot Here is the snapshot that I get when running with a patched JAR.
(In reply to comment #16) > Just to confirm, this is when you're running with > the hacked JAR? To clarify, the screenshots that I attached today, are based on the profiles that I attached to this defect on 2011/02/11, so they are before "the hacked jar".