I'm struggling with score corruption problem.
My case is based on timed customer vehicle routing example - I have a list of schedule allocations which are to start on particular metro stations and a list of employees (inspectors) who should visit them and do some work. The goal is allocate all tasks to these employees and to minimize transfers between the allocations.
I have set up a chained variable previousSlot, and added a custom shadow variable shadowStartTime which is supposed to be calculated based on the previous assignment.
Here is the planning entity:
@PlanningEntity
public class Allocation implements ScheduleSlot {
@AnchorShadowVariable(sourceVariableName = "previousSlot")
private Inspector inspector;
@PlanningVariable(
graphType=PlanningVariableGraphType.CHAINED,
valueRangeProviderRefs={"inspector_range", "task_range"} )
private ScheduleSlot previousSlot;
@CustomShadowVariable(variableListenerClass = SlotUpdateVariableListerer.class,
sources = {
@PlanningVariableReference(variableName = "inspector"),
@PlanningVariableReference(variableName = "previousSlot") })
private Long shadowStartTime;
...
Here, Inspector is a planning fact which is also an anchor, and ScheduleSlot is interface common to inspectors and allocations.
Variable listener is pretty simple too:
public class SlotUpdateVariableListerer implements VariableListener<ScheduleProblemSolution, ScheduleSlot> {
...
@Override
public void afterEntityAdded(ScoreDirector<ScheduleProblemSolution> scoreDirector, ScheduleSlot slot) {
updateTask(scoreDirector, slot);
}
@Override
public void afterVariableChanged(ScoreDirector<ScheduleProblemSolution> scoreDirector, ScheduleSlot slot) {
updateTask(scoreDirector, slot);
}
private void updateTask(ScoreDirector<ScheduleProblemSolution> scoreDirector, ScheduleSlot slot) {
ScheduleSlot prevSlot = slot.getPreviousSlot();
final Long startTime = prevSlot != null ? prevSlot.getFinishTime() + prevSlot.timeToNext(slot) : null;
scoreDirector.beforeVariableChanged(slot, "shadowStartTime");
((Allocation)slot).setShadowStartTime(startTime);
scoreDirector.afterVariableChanged(slot, "shadowStartTime");
}
}
And this fails if number of allocations > 2 right on the construction heuristics phase:
Exception in thread "main" java.lang.IllegalStateException: VariableListener corruption after completedAction ([09:00:00, 09:31:44] Task 321652 ...): The entity ([10:37:16, 11:14:24] Task 320522...)'s shadow variable (Allocation.shadowStartTime)'s corrupted value (1659940628000) changed to uncorrupted value (1659944236000) after all VariableListeners were triggered without changes to the genuine variables.
What could be wrong here?
UPD: Added a stack trace:
Exception in thread "main" java.lang.IllegalStateException:
VariableListener corruption after completedAction (...):
The entity (...)'s shadow variable (Allocation.shadowStartTime)'s corrupted value (...) changed to uncorrupted value (...) after all VariableListeners were triggered without changes to the genuine variables.
Maybe the VariableListener class (SlotUpdateVariableListerer) for that shadow variable (Allocation.shadowStartTime) forgot to update it when one of its sources changed.
at org.optaplanner.core.impl.score.director.AbstractScoreDirector.assertShadowVariablesAreNotStale(AbstractScoreDirector.java:520)
at org.optaplanner.core.impl.phase.scope.AbstractPhaseScope.assertShadowVariablesAreNotStale(AbstractPhaseScope.java:160)
at org.optaplanner.core.impl.phase.AbstractPhase.predictWorkingStepScore(AbstractPhase.java:147)
at org.optaplanner.core.impl.constructionheuristic.DefaultConstructionHeuristicPhase.doStep(DefaultConstructionHeuristicPhase.java:82)
at org.optaplanner.core.impl.constructionheuristic.DefaultConstructionHeuristicPhase.solve(DefaultConstructionHeuristicPhase.java:69)
at org.optaplanner.core.impl.solver.AbstractSolver.runPhases(AbstractSolver.java:83)
at org.optaplanner.core.impl.solver.DefaultSolver.solve(DefaultSolver.java:193)
at com.iconsoft.metro.opt.solver.ScheduleProblemSolution.solve(ScheduleProblemSolution.java:203)
at com.iconsoft.metro.opt.Main.main(Main.java:36)
UPD-2: Looks like this happens after anchor's entity reallocation:
23:56:43.328 DEBUG CH step (0), time spent (226), score (-59init/-5hard/0soft), selected move count (6), picked move (Task 320522: (uninitialized) {null -> Inspector #0}).
23:56:43.362 DEBUG CH step (1), time spent (260), score (-58init/-4hard/0soft), selected move count (7), picked move (Task 320527: (uninitialized) {null -> Inspector #1}).
23:56:43.396 DEBUG CH step (2), time spent (294), score (-57init/-3hard/0soft), selected move count (8), picked move (Task 321652: (uninitialized) {null -> Inspector #2}).
...
23:56:43.743 DEBUG CH step (8), time spent (641), score (-51init/-10hard/0soft), selected move count (14), picked move (Task 326806: (uninitialized) {null -> Inspector #0})
Exception in thread "main" java.lang.IllegalStateException: VariableListener corruption after completedAction()...
But I'm still unclear what does it mean...