Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.
Bug 309717 - [planner] explanation being computed even though a solution is supposed to exist
Summary: [planner] explanation being computed even though a solution is supposed to exist
Status: RESOLVED WORKSFORME
Alias: None
Product: Equinox
Classification: Eclipse Project
Component: p2 (show other bugs)
Version: 3.6   Edit
Hardware: PC Mac OS X - Carbon (unsup.)
: P3 major (vote)
Target Milestone: 3.6   Edit
Assignee: Daniel Le Berre CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2010-04-19 13:12 EDT by Johannes Rieken CLA
Modified: 2010-05-12 15:24 EDT (History)
2 users (show)

See Also:


Attachments
most recent gz file in the profileRegistry (445.37 KB, application/x-gzip)
2010-04-20 03:38 EDT, Johannes Rieken CLA
no flags Details
All Update Sites (Checked/Unchecked) (5.96 KB, application/xml)
2010-04-20 03:42 EDT, Johannes Rieken CLA
no flags Details
http://w3.zurich.ibm.com/~chn/jdojo-updatesite/content.jar:content.xml (486.66 KB, application/xml)
2010-04-21 06:48 EDT, Johannes Rieken CLA
no flags Details
file:/Users/riejo/Documents/ibm/rtc/head/update-site/site.xml (1.91 KB, application/xml)
2010-04-21 06:48 EDT, Johannes Rieken CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Johannes Rieken CLA 2010-04-19 13:12:03 EDT
Build Identifier: 3.6M6

* Invoke update manager
* Eclipse become stale in the UI thread

connecting jconsole tells me that there is some work going on the UI thread. 

Name: main
State: RUNNABLE
Total blocked: 26,015  Total waited: 13,641

Stack trace: 
java.math.BigInteger.equals(BigInteger.java:2509)
org.sat4j.pb.constraints.pb.WatchPb.sort(Unknown Source)
org.sat4j.pb.constraints.pb.WatchPb.sort(Unknown Source)
org.sat4j.pb.constraints.pb.WatchPb.sort(Unknown Source)
org.sat4j.pb.constraints.pb.WatchPb.sort(Unknown Source)
org.sat4j.pb.constraints.pb.WatchPb.sort(Unknown Source)
org.sat4j.pb.constraints.pb.WatchPb.sort(Unknown Source)
org.sat4j.pb.constraints.pb.WatchPb.sort(Unknown Source)
org.sat4j.pb.constraints.pb.WatchPb.sort(Unknown Source)
org.sat4j.pb.constraints.pb.WatchPb.sort(Unknown Source)
org.sat4j.pb.constraints.pb.WatchPb.sort(Unknown Source)
org.sat4j.pb.constraints.pb.WatchPb.sort(Unknown Source)
org.sat4j.pb.constraints.pb.WatchPb.<init>(Unknown Source)
org.sat4j.pb.constraints.pb.MaxWatchPb.<init>(Unknown Source)
org.sat4j.pb.constraints.pb.MaxWatchPb.normalizedMaxWatchPbNew(Unknown Source)
org.sat4j.pb.constraints.PBMaxClauseCardConstrDataStructure.constructPB(Unknown Source)
org.sat4j.pb.constraints.AbstractPBClauseCardConstrDataStructure.constraintFactory(Unknown Source)
org.sat4j.pb.constraints.AbstractPBDataStructureFactory.createPseudoBooleanConstraint(Unknown Source)
org.sat4j.pb.core.PBSolver.addPseudoBoolean(Unknown Source)
org.sat4j.pb.PBSolverDecorator.addPseudoBoolean(Unknown Source)
org.sat4j.pb.PseudoOptDecorator.discardCurrentSolution(Unknown Source)
org.sat4j.pb.OptToPBSATAdapter.model(Unknown Source)
org.sat4j.tools.SolverDecorator.model(Unknown Source)
org.sat4j.tools.xplain.Xplain.model(Unknown Source)
org.sat4j.pb.tools.DependencyHelper.getSolution(Unknown Source)
org.eclipse.equinox.internal.p2.director.Projector.backToIU(Projector.java:876)
org.eclipse.equinox.internal.p2.director.Projector.invokeSolver(Projector.java:852)
org.eclipse.equinox.internal.p2.director.SimplePlanner.getSolutionFor(SimplePlanner.java:305)
org.eclipse.equinox.internal.p2.director.SimplePlanner.getProvisioningPlan(SimplePlanner.java:351)
org.eclipse.equinox.internal.p2.operations.PlannerResolutionJob.runModal(PlannerResolutionJob.java:67)
org.eclipse.equinox.p2.operations.ProfileChangeOperation.resolveModal(ProfileChangeOperation.java:115)
org.eclipse.equinox.internal.p2.ui.sdk.UpdateHandler.doExecute(UpdateHandler.java:39)
org.eclipse.equinox.internal.p2.ui.sdk.PreloadingRepositoryHandler$2.run(PreloadingRepositoryHandler.java:57)
org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35)
org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:134)
   - locked org.eclipse.swt.widgets.RunnableLock@1d92e2a
org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:3549)
org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3243)
org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2416)
org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2380)
org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2229)
org.eclipse.ui.internal.Workbench$5.run(Workbench.java:504)
org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332)
org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:497)
org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149)
org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:115)
org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196)
org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110)
org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79)
org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:369)
org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:179)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
java.lang.reflect.Method.invoke(Method.java:597)
org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:619)
org.eclipse.equinox.launcher.Main.basicRun(Main.java:574)
org.eclipse.equinox.launcher.Main.run(Main.java:1406)


Reproducible: Always
Comment 1 Johannes Rieken CLA 2010-04-19 13:14:51 EDT
This is already going on since 10mins at 100% CPU usage.
Comment 2 Pascal Rapicault CLA 2010-04-19 13:57:57 EDT
Could you please attach the most recent gz file in <eclipseInstall>/p2/org.eclipse.equinox.p2.engine/profileRegistry/<someName>/

Also could you please provide an export (preferences > install / update > repos) of all repositories that you are running against.

Daniel, this is really weird since it means that we believe that there is a solution but when we are going to get it we are entering the computation of explanation.
Comment 3 Daniel Le Berre CLA 2010-04-19 14:49:54 EDT
Yes, it is really weird, because if there is a solution, we will basically enter in an infinite loop in Xplain.

The only possible cause I can think about is that the solver times out before we get a solution.

=> we should be careful before invoking explain to be sure that the answer was really unsat, not timeout.
Comment 4 Pascal Rapicault CLA 2010-04-19 14:54:41 EDT
The time out is handled in catch block that simply skip the code invoking the retrieval of the solution. Is there a code path where this would not be true in sat4j?
Comment 5 Susan McCourt CLA 2010-04-19 15:00:00 EDT
There was a similar case in bug 305810.
(note that bug is marked fix because we no longer block the UI while doing the work, but there was still many minutes spent on computing an explanation in that case.)
Comment 6 Daniel Le Berre CLA 2010-04-19 15:15:21 EDT
@pascal

The timeout is correctly handled in Projector.

however, I am unsure that we call the explanation only when an unsat answer is reported.

@susan

I changed the explanation engine in the latest release of SAT4J.
That should speed up the explanation in case of problem.
Comment 7 Pascal Rapicault CLA 2010-04-19 16:19:40 EDT
Johannes, please make sure to attach the data. This use case is definitely intriguing.
Comment 8 Daniel Le Berre CLA 2010-04-20 03:05:40 EDT
BTW, I decided to implement a new explanation algorithm because I noticed that the explanation computation was too long when I wanted to update from a 3.6M5 with JEE plugins to a fresh 3.6M6: the JEE updates where missing, which caused the launch of the explanation computation, that could take around one minute on my quad core computer.

This bug is maybe related to that, and the new explanation algorithm should sort that out.
Comment 9 Johannes Rieken CLA 2010-04-20 03:38:44 EDT
Created attachment 165381 [details]
most recent gz file in the profileRegistry
Comment 10 Johannes Rieken CLA 2010-04-20 03:42:47 EDT
Created attachment 165384 [details]
All Update Sites (Checked/Unchecked)
Comment 11 Pascal Rapicault CLA 2010-04-20 22:15:56 EDT
Could you please attach just the content.jar (or content.xml) for the following sites: 
  file:/Users/riejo/Documents/ibm/rtc/head/update-site/
  http://w3.zurich.ibm.com/~chn/jdojo-updatesite/

So we have a complete data set to reproduce this issue. Thx.
Comment 13 Johannes Rieken CLA 2010-04-21 06:48:56 EDT
Created attachment 165552 [details]
file:/Users/riejo/Documents/ibm/rtc/head/update-site/site.xml
Comment 14 Daniel Le Berre CLA 2010-04-22 17:11:03 EDT
Thanks Johannes. I created a testcase named Bug309717 with that information.
Comment 15 Pascal Rapicault CLA 2010-05-01 16:51:48 EDT
Unfortunately we don't have all the data necessary since the last site you update is a legacy update site (site.xml). Does this site contains a content.jar/xml? If not, could you please try to generate p2 metadata for it using the publisher: http://help.eclipse.org/galileo/index.jsp?topic=/org.eclipse.platform.doc.isv/guide/p2_publisher.html

Thx.
Comment 16 Pascal Rapicault CLA 2010-05-12 15:24:26 EDT
We don't have all the data and we fixed other things in this space. Closing for now. Please reopen if this happens with more recent versions.