[jboss-jira] [JBoss JIRA] (DROOLS-1174) Regression score corruption in dinner party probably due PLANNER-488

Geoffrey De Smet (JIRA) issues at jboss.org
Thu May 12 10:17:00 EDT 2016


     [ https://issues.jboss.org/browse/DROOLS-1174?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Geoffrey De Smet updated DROOLS-1174:
-------------------------------------
    Description: 
to reproduce run DinnerPartySolveAllTurtleTest with VM option -DrunTurtleTests=true in optaplanner-examples.

{code}
2016-05-12 16:06:02,121 [main] INFO  Opened: data/dinnerparty/unsolved/wedding01.xml
2016-05-12 16:06:02,226 [main] TRACE     Model annotations parsed for Solution DinnerParty:
2016-05-12 16:06:02,226 [main] TRACE         Entity SeatDesignation:
2016-05-12 16:06:02,226 [main] TRACE             Variable seat (genuine)
2016-05-12 16:06:03,436 [main] INFO  Solving started: time spent (137), best score (144uninitialized/-14400), environment mode (NON_INTRUSIVE_FULL_ASSERT), random (JDK with seed 0).
2016-05-12 16:06:03,913 [main] DEBUG     Custom step (0), time spent (615), score (-2890), new best score (-2890).
2016-05-12 16:06:03,913 [main] INFO  Custom phase (0) ended: step total (1), time spent (615), best score (-2890), score calculation speed (11050/sec).
2016-05-12 16:06:03,937 [main] TRACE     Created cachedMoveList: size (10368), moveSelector (Shuffling(Filtering(SwapMoveSelector(FromSolutionEntitySelector(SeatDesignation), FromSolutionEntitySelector(SeatDesignation))))).
2016-05-12 16:06:03,941 [main] TRACE     Shuffled cachedMoveList with size (10368) in moveSelector(Shuffling(Filtering(SwapMoveSelector(FromSolutionEntitySelector(SeatDesignation), FromSolutionEntitySelector(SeatDesignation))))).
2016-05-12 16:06:03,950 [main] TRACE         Move index (0), score (-2890), accepted (true), move (Grayson {1.4} <-> Oliver {0.4}).
2016-05-12 16:06:03,957 [main] TRACE         Move index (1), score (-2890), accepted (true), move (James {10.4} <-> Cameron {10.10}).

java.lang.IllegalStateException: Score corruption: the workingScore (-3190) is not the uncorruptedScore (-3090) after completedAction (Eliana {8.9} <-> Allison {9.3}):
  The corrupted scoreDirector has 1 ConstraintMatch(s) which are in excess (and should not be there):
    org.optaplanner.examples.dinnerparty.solver/twoSameJobTypePerTable/level0/[8, SOCIALITE]=-100
  The corrupted scoreDirector has no ConstraintMatch(s) which are missing.
  Check your score constraints.

	at org.optaplanner.core.impl.score.director.AbstractScoreDirector.assertWorkingScoreFromScratch(AbstractScoreDirector.java:418)
	at org.optaplanner.core.impl.solver.scope.DefaultSolverScope.assertWorkingScoreFromScratch(DefaultSolverScope.java:118)
	at org.optaplanner.core.impl.phase.scope.AbstractPhaseScope.assertWorkingScoreFromScratch(AbstractPhaseScope.java:156)
	at org.optaplanner.core.impl.localsearch.decider.LocalSearchDecider.processMove(LocalSearchDecider.java:167)
	at org.optaplanner.core.impl.localsearch.decider.LocalSearchDecider.doMove(LocalSearchDecider.java:153)
	at org.optaplanner.core.impl.localsearch.decider.LocalSearchDecider.decideNextStep(LocalSearchDecider.java:125)
	at org.optaplanner.core.impl.localsearch.DefaultLocalSearchPhase.solve(DefaultLocalSearchPhase.java:63)
	at org.optaplanner.core.impl.solver.DefaultSolver.runPhases(DefaultSolver.java:229)
	at org.optaplanner.core.impl.solver.DefaultSolver.solve(DefaultSolver.java:191)
	at org.optaplanner.examples.common.app.SolveAllTurtleTest.buildAndSolve(SolveAllTurtleTest.java:75)
	at org.optaplanner.examples.common.app.SolveAllTurtleTest.runFastAndFullAssert(SolveAllTurtleTest.java:55)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.junit.runners.Suite.runChild(Suite.java:128)
	at org.junit.runners.Suite.runChild(Suite.java:27)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
	at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:119)
	at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:42)
	at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234)
	at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)
{code}

I enabled trace logging above, it happens in the 3th move of the first step.

It seems like this rule is responsible:

{code}
// 1 democrat and 1 republican = 2 politians at each table but NOT two of the same kind
// 2 doctors at each table but NOT two of the same kind
// 2 coaches at each table but NOT two of the same kind
// 2 programmers at each table but NOT two of the same kind
// 2 socialites at each table
// 2 teachers at each table
rule "twoSameJobTypePerTable"
    when
        $jobType : JobType()
        $table : Table()
        not (
            SeatDesignation(guestJobType == $jobType, seatTable == $table, $leftId : id, $firstJob : guestJob)
            and SeatDesignation(guestJobType == $jobType, seatTable == $table, id > $leftId,
                    differentKindIfNeeded($firstJob))
        )
    then
        scoreHolder.addConstraintMatch(kcontext, -100);
end
{code}

  was:
to reproduce run DinnerPartySolveAllTurtleTest with VM option -DrunTurtleTests=true in optaplanner-examples.

{code}
2016-05-12 16:06:02,121 [main] INFO  Opened: data/dinnerparty/unsolved/wedding01.xml
2016-05-12 16:06:02,226 [main] TRACE     Model annotations parsed for Solution DinnerParty:
2016-05-12 16:06:02,226 [main] TRACE         Entity SeatDesignation:
2016-05-12 16:06:02,226 [main] TRACE             Variable seat (genuine)
2016-05-12 16:06:03,436 [main] INFO  Solving started: time spent (137), best score (144uninitialized/-14400), environment mode (NON_INTRUSIVE_FULL_ASSERT), random (JDK with seed 0).
2016-05-12 16:06:03,913 [main] DEBUG     Custom step (0), time spent (615), score (-2890), new best score (-2890).
2016-05-12 16:06:03,913 [main] INFO  Custom phase (0) ended: step total (1), time spent (615), best score (-2890), score calculation speed (11050/sec).
2016-05-12 16:06:03,937 [main] TRACE     Created cachedMoveList: size (10368), moveSelector (Shuffling(Filtering(SwapMoveSelector(FromSolutionEntitySelector(SeatDesignation), FromSolutionEntitySelector(SeatDesignation))))).
2016-05-12 16:06:03,941 [main] TRACE     Shuffled cachedMoveList with size (10368) in moveSelector(Shuffling(Filtering(SwapMoveSelector(FromSolutionEntitySelector(SeatDesignation), FromSolutionEntitySelector(SeatDesignation))))).
2016-05-12 16:06:03,950 [main] TRACE         Move index (0), score (-2890), accepted (true), move (Grayson {1.4} <-> Oliver {0.4}).
2016-05-12 16:06:03,957 [main] TRACE         Move index (1), score (-2890), accepted (true), move (James {10.4} <-> Cameron {10.10}).

java.lang.IllegalStateException: Score corruption: the workingScore (-3190) is not the uncorruptedScore (-3090) after completedAction (Eliana {8.9} <-> Allison {9.3}):
  The corrupted scoreDirector has 1 ConstraintMatch(s) which are in excess (and should not be there):
    org.optaplanner.examples.dinnerparty.solver/twoSameJobTypePerTable/level0/[8, SOCIALITE]=-100
  The corrupted scoreDirector has no ConstraintMatch(s) which are missing.
  Check your score constraints.

	at org.optaplanner.core.impl.score.director.AbstractScoreDirector.assertWorkingScoreFromScratch(AbstractScoreDirector.java:418)
	at org.optaplanner.core.impl.solver.scope.DefaultSolverScope.assertWorkingScoreFromScratch(DefaultSolverScope.java:118)
	at org.optaplanner.core.impl.phase.scope.AbstractPhaseScope.assertWorkingScoreFromScratch(AbstractPhaseScope.java:156)
	at org.optaplanner.core.impl.localsearch.decider.LocalSearchDecider.processMove(LocalSearchDecider.java:167)
	at org.optaplanner.core.impl.localsearch.decider.LocalSearchDecider.doMove(LocalSearchDecider.java:153)
	at org.optaplanner.core.impl.localsearch.decider.LocalSearchDecider.decideNextStep(LocalSearchDecider.java:125)
	at org.optaplanner.core.impl.localsearch.DefaultLocalSearchPhase.solve(DefaultLocalSearchPhase.java:63)
	at org.optaplanner.core.impl.solver.DefaultSolver.runPhases(DefaultSolver.java:229)
	at org.optaplanner.core.impl.solver.DefaultSolver.solve(DefaultSolver.java:191)
	at org.optaplanner.examples.common.app.SolveAllTurtleTest.buildAndSolve(SolveAllTurtleTest.java:75)
	at org.optaplanner.examples.common.app.SolveAllTurtleTest.runFastAndFullAssert(SolveAllTurtleTest.java:55)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.junit.runners.Suite.runChild(Suite.java:128)
	at org.junit.runners.Suite.runChild(Suite.java:27)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
	at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:119)
	at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:42)
	at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234)
	at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)
{code}

I enabled trace logging above, it happens in the 3th move of the first step.



> Regression score corruption in dinner party probably due PLANNER-488
> --------------------------------------------------------------------
>
>                 Key: DROOLS-1174
>                 URL: https://issues.jboss.org/browse/DROOLS-1174
>             Project: Drools
>          Issue Type: Bug
>          Components: core engine
>            Reporter: Geoffrey De Smet
>            Assignee: Mario Fusco
>
> to reproduce run DinnerPartySolveAllTurtleTest with VM option -DrunTurtleTests=true in optaplanner-examples.
> {code}
> 2016-05-12 16:06:02,121 [main] INFO  Opened: data/dinnerparty/unsolved/wedding01.xml
> 2016-05-12 16:06:02,226 [main] TRACE     Model annotations parsed for Solution DinnerParty:
> 2016-05-12 16:06:02,226 [main] TRACE         Entity SeatDesignation:
> 2016-05-12 16:06:02,226 [main] TRACE             Variable seat (genuine)
> 2016-05-12 16:06:03,436 [main] INFO  Solving started: time spent (137), best score (144uninitialized/-14400), environment mode (NON_INTRUSIVE_FULL_ASSERT), random (JDK with seed 0).
> 2016-05-12 16:06:03,913 [main] DEBUG     Custom step (0), time spent (615), score (-2890), new best score (-2890).
> 2016-05-12 16:06:03,913 [main] INFO  Custom phase (0) ended: step total (1), time spent (615), best score (-2890), score calculation speed (11050/sec).
> 2016-05-12 16:06:03,937 [main] TRACE     Created cachedMoveList: size (10368), moveSelector (Shuffling(Filtering(SwapMoveSelector(FromSolutionEntitySelector(SeatDesignation), FromSolutionEntitySelector(SeatDesignation))))).
> 2016-05-12 16:06:03,941 [main] TRACE     Shuffled cachedMoveList with size (10368) in moveSelector(Shuffling(Filtering(SwapMoveSelector(FromSolutionEntitySelector(SeatDesignation), FromSolutionEntitySelector(SeatDesignation))))).
> 2016-05-12 16:06:03,950 [main] TRACE         Move index (0), score (-2890), accepted (true), move (Grayson {1.4} <-> Oliver {0.4}).
> 2016-05-12 16:06:03,957 [main] TRACE         Move index (1), score (-2890), accepted (true), move (James {10.4} <-> Cameron {10.10}).
> java.lang.IllegalStateException: Score corruption: the workingScore (-3190) is not the uncorruptedScore (-3090) after completedAction (Eliana {8.9} <-> Allison {9.3}):
>   The corrupted scoreDirector has 1 ConstraintMatch(s) which are in excess (and should not be there):
>     org.optaplanner.examples.dinnerparty.solver/twoSameJobTypePerTable/level0/[8, SOCIALITE]=-100
>   The corrupted scoreDirector has no ConstraintMatch(s) which are missing.
>   Check your score constraints.
> 	at org.optaplanner.core.impl.score.director.AbstractScoreDirector.assertWorkingScoreFromScratch(AbstractScoreDirector.java:418)
> 	at org.optaplanner.core.impl.solver.scope.DefaultSolverScope.assertWorkingScoreFromScratch(DefaultSolverScope.java:118)
> 	at org.optaplanner.core.impl.phase.scope.AbstractPhaseScope.assertWorkingScoreFromScratch(AbstractPhaseScope.java:156)
> 	at org.optaplanner.core.impl.localsearch.decider.LocalSearchDecider.processMove(LocalSearchDecider.java:167)
> 	at org.optaplanner.core.impl.localsearch.decider.LocalSearchDecider.doMove(LocalSearchDecider.java:153)
> 	at org.optaplanner.core.impl.localsearch.decider.LocalSearchDecider.decideNextStep(LocalSearchDecider.java:125)
> 	at org.optaplanner.core.impl.localsearch.DefaultLocalSearchPhase.solve(DefaultLocalSearchPhase.java:63)
> 	at org.optaplanner.core.impl.solver.DefaultSolver.runPhases(DefaultSolver.java:229)
> 	at org.optaplanner.core.impl.solver.DefaultSolver.solve(DefaultSolver.java:191)
> 	at org.optaplanner.examples.common.app.SolveAllTurtleTest.buildAndSolve(SolveAllTurtleTest.java:75)
> 	at org.optaplanner.examples.common.app.SolveAllTurtleTest.runFastAndFullAssert(SolveAllTurtleTest.java:55)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:498)
> 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> 	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> 	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> 	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> 	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> 	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> 	at org.junit.runners.Suite.runChild(Suite.java:128)
> 	at org.junit.runners.Suite.runChild(Suite.java:27)
> 	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> 	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> 	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> 	at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
> 	at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:119)
> 	at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:42)
> 	at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234)
> 	at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:498)
> 	at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)
> {code}
> I enabled trace logging above, it happens in the 3th move of the first step.
> It seems like this rule is responsible:
> {code}
> // 1 democrat and 1 republican = 2 politians at each table but NOT two of the same kind
> // 2 doctors at each table but NOT two of the same kind
> // 2 coaches at each table but NOT two of the same kind
> // 2 programmers at each table but NOT two of the same kind
> // 2 socialites at each table
> // 2 teachers at each table
> rule "twoSameJobTypePerTable"
>     when
>         $jobType : JobType()
>         $table : Table()
>         not (
>             SeatDesignation(guestJobType == $jobType, seatTable == $table, $leftId : id, $firstJob : guestJob)
>             and SeatDesignation(guestJobType == $jobType, seatTable == $table, id > $leftId,
>                     differentKindIfNeeded($firstJob))
>         )
>     then
>         scoreHolder.addConstraintMatch(kcontext, -100);
> end
> {code}



--
This message was sent by Atlassian JIRA
(v6.4.11#64026)


More information about the jboss-jira mailing list