[jboss-jira] [JBoss JIRA] (JBRULES-3525) Planner causes score corruption (and doesn't even detect it)

[Geoffrey De Smet (JIRA)]

    [ https://issues.jboss.org/browse/JBRULES-3525?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12698380#comment-12698380 ] 

Geoffrey De Smet commented on JBRULES-3525:
-------------------------------------------

Can you try with environmentMode TRACE but with something like:
((DefaultDecider)
 ((DefaultLocalSearchSolverPhase) 
  ((DefaultSolver) solver).getSolverPhases().get(1)
 ).getDecider())
.setAssertUndoMoveIsUncorrupted(false)

And also with environmentMode default (REPRODICABLE) with setAssertUndoMoveIsUncorrupted(true)?

My guess is that setAssertUndoMoveIsUncorrupted(true) is causing difference between TRACE and non TRACE.
                
> Planner causes score corruption (and doesn't even detect it)
> ------------------------------------------------------------
>
>                 Key: JBRULES-3525
>                 URL: https://issues.jboss.org/browse/JBRULES-3525
>             Project: Drools
>          Issue Type: Bug
>      Security Level: Public(Everyone can see) 
>          Components: drools-planner
>    Affects Versions: 5.5.0.Beta1
>            Reporter: Lukáš Petrovický
>            Assignee: Geoffrey De Smet
>         Attachments: runtime.log
>
>
> Using incremental score calculation, I've been having weird problems where solutions have outdated scores. These scores are "fixed" when I explicitly call my score calculator on them. After tons of debugging, I was able to produce the attached simplified log file. I will explain it here:
> ItineraryAssignment is a planning entity. Lines as these should be clear:
> 21:28:33.377 [main] DEBUG o.d.p.e.ras2012.ScoreCalculator - Inserting entity: ItineraryAssignment [train=A1, route=0]
> 21:28:33.377 [main] DEBUG o.d.p.e.ras2012.ScoreCalculator - Inserting entity: ItineraryAssignment [train=A1, route=0]
> Lines like this signify that calculateScore() was called on the calculator:
> 21:28:33.833 [main] DEBUG o.d.p.e.ras2012.ScoreCalculator - Calculating score.
> Lines like this mean that setScore() has been called on a Solution. They will finally demonstrate the problem:
> 21:28:33.867 [main] DEBUG o.d.p.e.ras2012.ProblemSolution - Setting score -968hard/-3409soft to solution RAS2012Solution ...
> What we see in the log file is that after a move is done, score is properly re-calculated and set:
> 21:28:33.922 [main] DEBUG o.d.p.e.r.move.RouteReassignmentMove - Doing move RouteReassignmentMove [train=A2, 0 -> 256].
> 21:28:34.215 [main] DEBUG o.d.p.e.ras2012.ScoreCalculator - Removing entity: ItineraryAssignment [train=A2, route=0]
> 21:28:34.216 [main] DEBUG o.d.p.e.r.model.ItineraryAssignment - Creating new itinerary for ItineraryAssignment [train=A2, route=256].
> 21:28:34.216 [main] DEBUG o.d.p.e.ras2012.ScoreCalculator - Inserting entity: ItineraryAssignment [train=A2, route=256]
> 21:28:34.223 [main] DEBUG o.d.p.e.ras2012.ScoreCalculator - Calculating score.
> 21:28:34.232 [main] DEBUG o.d.p.e.ras2012.ProblemSolution - Setting score -300hard/-1294soft to solution RAS2012Solution ...
> However, on the undo move for the very same move, no score calculation takes place, no setScore() takes place and no solution is cloned. Resulting in Solution with outdated score:
> 21:28:34.232 [main] DEBUG o.d.p.e.r.m.RouteReassignmentUndoMove - Doing move RouteReassignmentUndoMove [train=A2, 256 -> 0].
> 21:28:34.297 [main] DEBUG o.d.p.e.ras2012.ScoreCalculator - Removing entity: ItineraryAssignment [train=A2, route=256]
> 21:28:34.299 [main] DEBUG o.d.p.e.r.model.ItineraryAssignment - Creating new itinerary for ItineraryAssignment [train=A2, route=0].
> 21:28:34.299 [main] DEBUG o.d.p.e.ras2012.ScoreCalculator - Inserting entity: ItineraryAssignment [train=A2, route=0]
> 21:28:34.305 [main] TRACE o.d.p.c.l.decider.DefaultDecider -         Move score (-300hard/-1294soft), accepted (true) for move (RouteReassignmentMove [train=A2, 0 -> 256]).
> Which is why the move directly after that (which has been hard-coded to throw exception when the score doesn't match the expected one) throws an exception:
> 21:28:34.305 [main] DEBUG o.d.p.e.r.move.RouteReassignmentMove - Doing move RouteReassignmentMove [train=A2, 0 -> 274].
> Exception in thread "main" java.lang.IllegalStateException: RouteReassignmentMove [train=A2, 0 -> 274]: broken score found. Was -300hard/-1294soft but -968hard/-3409soft expected.
> 	at org.drools.planner.examples.ras2012.move.CommonMove.assertValidScore(CommonMove.java:16)
> ...
> Furthermore, setting environmentMode to TRACE actually fixes the issue - this suggests to me that Planner forgets to calculate the score somewhere and TRACE does it instead.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira