[ https://issues.jboss.org/browse/JBRULES-3525?page=com.atlassian.jira.plug... ] Lukáš Petrovický commented on JBRULES-3525: ------------------------------------------- To reproduce, run code on the following branch: https://github.com/triceo/ras12/tree/JBRULES-3525 (Just the ras2012-solver module. Others may not even compile, it's a work in progress.) -- 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

[ https://issues.jboss.org/browse/JBRULES-3525?page=com.atlassian.jira.plug... ] Lukáš Petrovický updated JBRULES-3525: -------------------------------------- Description: 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. was: 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 doesn't help here. This goes completely undetected. -- 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

[ https://issues.jboss.org/browse/JBRULES-3525?page=com.atlassian.jira.plug... ] Lukáš Petrovický commented on JBRULES-3525: ------------------------------------------- Setting the thing to true fixes the issue. -- 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

[ https://issues.jboss.org/browse/JBRULES-3525?page=com.atlassian.jira.plug... ] Geoffrey De Smet resolved JBRULES-3525. --------------------------------------- Fix Version/s: 5.5.0.Beta1 Resolution: Done There is now an assertion in BestSolutionRecaller that detects this kind of bugs in TRACE mode. Please reopen if it's verified that the actual bug is in planner code. -- 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