Bug 356888

Comment 1 Benjamin Cabé 2011-09-21 04:59:08 EDT

I have noticed the same behaviour. One of our builds has a performance drop of about 2.5x (20 min -> 55 min!).
We use an explicit target definition (.target file), whose referenced repositories are mirrors on our intranet.

Comment 2 Eric Jain 2011-09-27 19:01:26 EDT

The time to get from "Scanning for projects..." to "Reactor Build Order:" has increased from under 4min to over 20min (!) for us after upgrading from Tycho 0.10.0 to 0.13.0. The build contains ~100 modules.

Comment 3 Igor Fedorenko 2011-09-27 20:12:29 EDT

We need more fine grained measurements to be able to troubleshoot the problem. Or a standalone example project.

Comment 4 Eric Jain 2011-09-28 20:18:13 EDT

Created attachment 204235 [details]
Call Tree

Attached a call tree recorded with JProfiler, from the start of the build until all the "Resolving target platform" are done.

Comment 5 Eric Jain 2011-09-30 20:41:32 EDT

I replaced the .target file with a single, local p2 repository. Unfortunately this doesn't cut down the build time much (i.e. 26min vs 28min).

The performance drop is all before the build gets to logging "Reactor Build Order". For each module there is a log entry "[INFO] Adding repository (cached) http://..." which appears to take 7-10s.

Comment 6 Igor Fedorenko 2011-10-04 21:15:56 EDT

I can't tell anything definitive from the attached execution profile and another execution profile I got via email. None of my projects is affected by this problem either, so I can't tell what triggers it. Need a standalone example project to troubleshoot this.

Comment 7 Jan Sievers 2011-10-05 03:32:55 EDT

(In reply to comment #6)
> I can't tell anything definitive from the attached execution profile and
> another execution profile I got via email. None of my projects is affected by
> this problem either, so I can't tell what triggers it. Need a standalone
> example project to troubleshoot this.

From talking to Tobias previously I think he has a pretty good idea what caused the performance drop; may be worth waiting for him to come back from vacation to shed some light here.

Comment 8 Tobias Oberlies 2011-10-05 09:17:18 EDT

There is one pretty obvious thing which we should fix first before investigating further: 
In Tycho 0.13.0, target definition files are (for the first time) interpreted correctly. This requires some potentially costly calls to p2, so the build is expected to take longer with 0.13.0 than with 0.12.0.
Still, the current implementation is unnecessarily slow: In the loop which computes the target _platform_ [1] for each module, the target _definition file_ is resolved over and over again. We obviously need a cache for this.

[1] http://wiki.eclipse.org/Tycho/Glossary

Comment 9 Tobias Oberlies 2011-10-06 03:51:08 EDT

(In reply to comment #5)
> I replaced the .target file with a single, local p2 repository. Unfortunately
> this doesn't cut down the build time much (i.e. 26min vs 28min).
You removed the target file in the target-platform-configuration and the build performance still doesn't improve significantly? This probably means that you have a different problem. How does 0.12.0 compare to 0.13.0 in your build?

Comment 10 Eric Jain 2011-10-06 14:25:51 EDT

(In reply to comment #9)
> You removed the target file in the target-platform-configuration and the build
> performance still doesn't improve significantly? This probably means that you
> have a different problem. How does 0.12.0 compare to 0.13.0 in your build?

If I downgrade to 0.12.0 I get:

java.lang.IllegalArgumentException: Format "format(n[.n=0;[.n=0;[.S=[A-Za-z0-9_-];='';]]])" was unable to parse null
  at org.eclipse.equinox.internal.p2.metadata.VersionFormat.parse(VersionFormat.java:273)
  at ...

But here's another interesting observation: After clearing the .m2 cache (and doing a build to repopulate the cache), the build time is down to 17min. That's still 5min slower than it used to be with 0.10.0, but a big improvement.

Comment 11 Igor Fedorenko 2011-10-06 14:36:05 EDT

we need sample standalone projects the demonstrate the performance drop.

Comment 12 Tobias Oberlies 2011-10-10 04:01:26 EDT

(In reply to comment #10)
> But here's another interesting observation: After clearing the .m2 cache (and
> doing a build to repopulate the cache), the build time is down to 17min. That's
> still 5min slower than it used to be with 0.10.0, but a big improvement.
This may be related to the time it takes to load the local Maven repository as p2 IArtifactRepository (see org.eclipse.tycho.p2.maven.repository.LocalArtifactRepository). The more p2 artifacts are in the local Maven repository, the longer it takes. Still, this shouldn't have changed much between 0.12 and 0.13.
Currently, there is one LocalArtifactRepository instances per module, so sharing one instance (and hence only reading the local Maven repo) could give a performance improvement.

Comment 13 Tobias Oberlies 2011-10-21 05:03:31 EDT

(In reply to comment #2)
> The time to get from "Scanning for projects..." to "Reactor Build Order:" has
> increased from under 4min to over 20min (!) for us after upgrading from Tycho
> 0.10.0 to 0.13.0. The build contains ~100 modules.

I think I have just fixed a major performance bug introduced in 0.11.0: bug 361619. Could you check how this affects your build times? Unfortunately there are no CI build results for 0.14.0-SNAPSHOT, so you'll need to build Tycho from source. The good news: it's as easy as calling mvn clean install in the project root (see [1] for details).

[1] http://wiki.eclipse.org/Developing_Tycho

Comment 14 Eric Jain 2011-10-21 18:13:16 EDT

(In reply to comment #13)
> I think I have just fixed a major performance bug introduced in 0.11.0: bug
> 361619. Could you check how this affects your build times? Unfortunately there
> are no CI build results for 0.14.0-SNAPSHOT, so you'll need to build Tycho from
> source. The good news: it's as easy as calling mvn clean install in the project
> root (see [1] for details).
> 
> [1] http://wiki.eclipse.org/Developing_Tycho

I couldn't do a full build with 0.14.0-SNAPSHOT (surefire fails), but the slow bit (i.e. the time required to get to "[INFO] Reactor Build Order") is 8 min compared to 9-10 min with 0.13.0, and 3 min with 0.10.0.

0.14.0-SNAPSHOT appears to generate the same logging output as 0.13.0.

Comment 15 Tobias Oberlies 2013-02-06 04:53:39 EST

(In reply to comment #4)
> Created attachment 204235 [details]
> Call Tree
> 
> Attached a call tree recorded with JProfiler, from the start of the build
> until all the "Resolving target platform" are done.

Thanks Eric for this useful analysis. I've just looked at this again and it seems that the two largest problems have been addressed: re-resolution of the target file (bug 373806) and the zip operation on the target folder of the previous build (bug 361619).

I'll therefore mark this bug as fixed. If someone discovers more potential for improvement, please open a new bug.