Description Stefan Zugal 2017-02-14 05:50:35 EST

Created attachment 266808 [details]
The setup for reproducing the problem

The resolving of bundles takes long (around 1 minute) under certain circumstances. I tried to distill the environment as far as I could - it should be reproducible as follows:

* Download Virgo 3.7.0.RC01 from here: http://www.eclipse.org/downloads/download.php?file=/virgo/milestone/VTS/virgo-tomcat-server-3.7.0.RC01.zip
* Download the attachment.zip from this bug and extract it
** Copy folder "user" from the attachment into the folder "virgo/repository"
** Copy the file "at.ches.pro.trunk.main.plan" into the folder "virgo/pickup"
** Copy the file .options into the folder "virgo"
* Add "repository:plan/org.eclipse.virgo.snaps" to the initialArtifacts in file virgo/configuration/org.eclipse.virgo.kernel.userregion.properties
* Open a shell
* Export the debug option: export LAUNCH_OPTS="-debug"
* Start Virgo: virgo/bin/startup.sh

Virgo should now start and after around 10 seconds the following lines should be visible on the console:
[2017-02-14 11:35:44.682] fs-watcher <DE0000I> Installing bundle 'at.ches.pro.trunk.main-5.17-at.ches.pro.web.nurse' version '5.17.0.201612031629'. 

Here the troubles start, since the resolving takes place (these lines appear after 30 and 20 seconds):
Time spent resolving: 287
Time spent resolving: 32551
Time spent resolving: 21642

If you look at virgo/serviceability/logs/log.log, just after installing the plan at.ches.pro.trunk.main.plan, the following lines should appear:
[2017-02-14 11:36:18.895] INFO  fs-watcher	System.out	[1,1,1,1,1,0,2,0,0]
[2017-02-14 11:36:18.939] INFO  fs-watcher	System.out	Combination is not better than current best: 176>=172
[2017-02-14 11:36:18.939] INFO  fs-watcher	System.out	[0,2,1,1,1,0,2,0,0]
[2017-02-14 11:36:18.986] INFO  fs-watcher	System.out	Combination is not better than current best: 172>=172
[2017-02-14 11:36:18.986] INFO  fs-watcher	System.out	Uses constraint check has timedout.  Using the best solution found so far.
[2017-02-14 11:36:18.986] INFO  fs-watcher	System.out	Best combination found: [0,0,0,0,0,0,0,0,0]


It seems like the most time is spent in org.eclipse.osgi.internal.module.ResolverImpl.checkUsesConstraints, which also produces the debug output above. Please let me know whether you can reproduce the behaviour using this setup.