search

google / or-tools

Google's Operations Research tools:
https://developers.google.com/optimization/
Apache License 2.0
11.1k stars 2.11k forks source link

Timeout not respected when using multiple-phase decision builder #2723

Closed ChristopherHamkins closed 2 years ago

ChristopherHamkins commented 3 years ago

What version of OR-Tools and what language are you using? Version: 9.0.9048 (also present in 6.7.4973) Language: C#

Which solver are you using Routing Solver

What operating system Windows 10

What did you do? I have a problem that timeout is not respected when using multiple-phase decision builders and the solution can't be found because of massive backtracking.

Steps to reproduce the behavior:

This is a minimal code that demonstrates the problem:

using Google.OrTools.ConstraintSolver;
using System;

namespace GoogleORToolsConstraintSolverTimeoutExample
{
    public class BacktrackingTimeoutModel
    {
        internal int nVars = 8;
        internal const int nValMin = 0;
        internal int nValMax = 9;
        internal const int nPermute = 1;
        internal const int nTrivialSolutions = 2;
        internal const int timeLimit_ms = 1000;

        IntVar[] decisionVariables;
        IntVar[] permutationVariables;
        IntVar[] restOfTheVariables;

        public BacktrackingTimeoutModel(int nVars_, int nValMax_)
        {
            this.nVars = nVars_;
            this.nValMax = nValMax_;
        }

        public static Solver getSolver()
        {
            ConstraintSolverParameters solverpara = Solver.DefaultSolverParameters();
            // solverpara.TraceSearch = true;
            solverpara.PrintModelStats = true;
            var solver = new Solver("Test", solverpara);
            return solver;
        }

        public void InitModel(Solver solver)
        {
            // All the variables in the model
            decisionVariables = new IntVar[nVars];
            for (int i = 0; i < nVars; i++)
            {
                decisionVariables[i] = solver.MakeIntVar(nValMin, nValMax, string.Format("Var{0,3:D3}", i));
            }
            // Variables for which we want all solutions
            permutationVariables = new IntVar[nPermute];
            for (int i = 0; i < nPermute; i++)
            {
                permutationVariables[i] = decisionVariables[i];
            }
            // Variables for which we want only one solution
            int nRest = nVars - nPermute;
            restOfTheVariables = new IntVar[nRest];
            for (int i = 0; i < nRest; i++)
            {
                restOfTheVariables[i] = decisionVariables[i + nPermute];
            }

            // For trivial solutions, constrain all values equal to the first one for several of its values.
            for (int j = 0; j < nTrivialSolutions; j++)
            {
                int valueForAll = j + nValMin;
                IntExpr firstVariableIsNotEqual = (decisionVariables[0] != valueForAll);
                for (int i = 1; i < nVars; i++)
                {
                    solver.Add(solver.MakeMax(firstVariableIsNotEqual, (decisionVariables[i] == valueForAll)) == 1);
                }
            }
        }

        public void addFixedValueConstraint()
        {
            Solver solver = decisionVariables[0].solver();
            solver.Add(decisionVariables[0] == 2L);
        }

        public void solveModel(Solver solver, DecisionBuilder decisionBuilder)
        {

            // Search limits
            SearchLimit limits = solver.MakeLimit(timeLimit_ms, long.MaxValue, long.MaxValue, long.MaxValue, true, true);

            // Start a new search
            solver.NewSearch(decisionBuilder, limits);

            // Find all solutions
            int nsols = 0;
            while (solver.NextSolution())
            {
                nsols++;
                Console.WriteLine("\r\nSolution {0}:", nsols);
                for (int i = 0; i < nVars; i++)
                {
                    Console.WriteLine("{0} = {1}", decisionVariables[i].Name(), decisionVariables[i].Value());
                }
            }
            Console.WriteLine("\r\nLimit reached: {0}", limits.IsCrossed());

            // Solver-Statistik ausgeben
            Console.WriteLine("\r\nSolver:" + solver.ToString());
            Console.WriteLine(string.Format("State: {0}", solver.State()));
            Console.WriteLine(string.Format("Number of solutions: {0}", solver.Solutions()));
            Console.WriteLine(string.Format("WallTime: {0} ms", solver.WallTime()));
            Console.WriteLine(string.Format("Failures: {0}", solver.Failures()));
            Console.WriteLine(string.Format("Branches: {0} ", solver.Branches()));
            Console.WriteLine(string.Format("Memory: {0} ", Solver.MemoryUsage()));
        }

        internal DecisionBuilder makePermutationDecisionBuilder(Solver solver)
        {
            // Decision builder for permutation variables
            DecisionBuilder permutationDecisionBuilder = new StandardDecisionBuilder(permutationVariables);

            // Decision builder for the rest of the variables
            DecisionBuilder restDecisionBuilder = new MassiveBacktrackingDecisionBuilder(decisionVariables);

            // But we only want a single solution for the rest while permuting the first
            DecisionBuilder singleSolutionDecisionBuilder = solver.MakeSolveOnce(restDecisionBuilder);

            // The composite decision builder combines these two phases
            DecisionBuilder decisionBuilder = solver.Compose(permutationDecisionBuilder, singleSolutionDecisionBuilder);
            return decisionBuilder;
        }
        internal DecisionBuilder makeSinglePhaseDecisionBuilder(Solver solver)
        {
            return new MassiveBacktrackingDecisionBuilder(decisionVariables);
        }

    }

    /// <summary>
    /// Decision builder designed to always fail on the decision for the last variable.
    /// The dependency can therefore only be discovered via backtracking.
    /// </summary>
    public class MassiveBacktrackingDecisionBuilder : DecisionBuilder
    {
        private IntVar[] decisionVariables;

        public MassiveBacktrackingDecisionBuilder(IntVar[] decisionVariables_)
        {
            this.decisionVariables = decisionVariables_ ?? throw new ArgumentNullException(nameof(decisionVariables_));
        }

        public override Decision NextWrapper(Solver solver)
        {
            // Find first unbound variable
            int firstUnbound = -1;
            for (int i = 0; i < decisionVariables.Length; i++)
            {
                if (!decisionVariables[i].Bound())
                {
                    firstUnbound = i;
                    break;
                }
            }

            // Everything bound? Then we're done (although theoretically this shouldn't happen here...
            if (firstUnbound == -1)
            {
                return null;
            }

            // For all variables except the last, return the minimum value still in the domain
            if (firstUnbound < decisionVariables.Length - 1)
            {
                return solver.MakeAssignVariableValue(decisionVariables[firstUnbound], decisionVariables[firstUnbound].Min());
            }

            // For the last variable, always return a fail decision
            // unless the first variable corresponds to one of the trival solutions.
            if (decisionVariables[0].Value() < BacktrackingTimeoutModel.nTrivialSolutions + BacktrackingTimeoutModel.nValMin)
            {
                return solver.MakeAssignVariableValue(decisionVariables[firstUnbound], decisionVariables[firstUnbound].Min());
            }
            // Otherwise return a fail decision to force into backtracking.
            return solver.MakeFailDecision();
        }
    }

    /// <summary>
    /// Decision builder designed to always simply return min of first unbound variable as decision
    /// </summary>
    public class StandardDecisionBuilder : DecisionBuilder
    {
        private IntVar[] decisionVariables;

        public StandardDecisionBuilder(IntVar[] decisionVariables_)
        {
            this.decisionVariables = decisionVariables_ ?? throw new ArgumentNullException(nameof(decisionVariables_));
        }

        public override Decision NextWrapper(Solver solver)
        {
            // Find first unbound variable
            int firstUnbound = -1;
            for (int i = 0; i < decisionVariables.Length; i++)
            {
                if (!decisionVariables[i].Bound())
                {
                    firstUnbound = i;
                    break;
                }
            }

            // Everything bound? Then we're done
            if (firstUnbound == -1)
            {
                return null;
            }

            // Otherwise return min value still in the domain
            return solver.MakeAssignVariableValue(decisionVariables[firstUnbound], decisionVariables[firstUnbound].Min());
        }
    }
}

I execute it like this for the test:

using System;
using Google.OrTools.ConstraintSolver;

namespace GoogleORToolsConstraintSolverTimeoutExample
{
    class Program
    {
        static void Main(string[] args)
        {
            Console.WriteLine("\r\nWith only a few variables and values, we can finish within the timeout.");
            BacktrackingTimeoutModel model = new BacktrackingTimeoutModel(4, 4);
            Solver solver = BacktrackingTimeoutModel.getSolver();
            model.InitModel(solver);
            DecisionBuilder decisionBuilder = model.makeSinglePhaseDecisionBuilder(solver);
            model.solveModel(solver, decisionBuilder);

            Console.WriteLine("\r\nAdding a fixed value constraint makes the model infeasible, which is discovered within the timeout.");
            model = new BacktrackingTimeoutModel(4, 4);
            solver = BacktrackingTimeoutModel.getSolver();
            model.InitModel(solver);
            model.addFixedValueConstraint();
            decisionBuilder = model.makeSinglePhaseDecisionBuilder(solver);
            model.solveModel(solver, decisionBuilder);

            Console.WriteLine("\r\nWith more variables and a single phase, the specified timeout is reached and respected.");
            model = new BacktrackingTimeoutModel(8, 9);
            solver = BacktrackingTimeoutModel.getSolver();
            model.InitModel(solver);
            model.addFixedValueConstraint();
            decisionBuilder = model.makeSinglePhaseDecisionBuilder(solver);
            model.solveModel(solver, decisionBuilder);

            Console.WriteLine("\r\nWith more variables and a single phase but without the fixed value constraint, " +
                "the specified timeout is reached and respected.");
            model = new BacktrackingTimeoutModel(9, 9);
            solver = BacktrackingTimeoutModel.getSolver();
            model.InitModel(solver);
            decisionBuilder = model.makeSinglePhaseDecisionBuilder(solver);
            model.solveModel(solver, decisionBuilder);

            Console.WriteLine("\r\nBut without the fixed value constraint and multiple phases, after finding two solutions the timeout is exceeded.");
            model = new BacktrackingTimeoutModel(9, 9);
            solver = BacktrackingTimeoutModel.getSolver();
            model.InitModel(solver);
            decisionBuilder = model.makePermutationDecisionBuilder(solver);
            model.solveModel(solver, decisionBuilder);

            Console.WriteLine("Press any key to continue...");
            Console.ReadKey();
        }
    }
}

Execute the Main method. This is the output:

With only a few variables and values, we can finish within the timeout.
WARNING: Logging before InitGoogleLogging() is written to STDERR
I00-1 -1:-1:-1.456787 20680 utilities.cc:554] Model has:
I00-1 -1:-1:-1.684570 20680 utilities.cc:555]   - 14 constraints.
I00-1 -1:-1:-1.062988 20680 utilities.cc:557]     * 6 Equal
I00-1 -1:-1:-1.136718 20680 utilities.cc:557]     * 4 VarBoundWatcher
I00-1 -1:-1:-1.177246 20680 utilities.cc:557]     * 4 VarValueWatcher
I00-1 -1:-1:-1.250732 20680 utilities.cc:559]   - 16 integer variables.
I00-1 -1:-1:-1.379882 20680 utilities.cc:560]   - 6 integer expressions.
I00-1 -1:-1:-1.453369 20680 utilities.cc:562]     * 6 Max
I00-1 -1:-1:-1.547119 20680 utilities.cc:564]   - 4 expressions casted into variables.
I00-1 -1:-1:-1.630126 20680 utilities.cc:565]   - 0 interval variables.
I00-1 -1:-1:-1.705078 20680 utilities.cc:566]   - 0 sequence variables.
I00-1 -1:-1:-1.765869 20680 utilities.cc:567]   - 0 model extensions.

Solution 1:
Var000 = 0
Var001 = 0
Var002 = 0
Var003 = 0

Solution 2:
Var000 = 1
Var001 = 1
Var002 = 1
Var003 = 1

Limit reached: False

Solver:Solver(name = "Test", state = NO_MORE_SOLUTIONS, branches = 152, fails = 75, decisions = 76, delayed demon runs = 0, var demon runs = 265, normal demon runs = 350, Run time = 14 ms)
State: 4
Number of solutions: 2
WallTime: 15 ms
Failures: 75
Branches: 152
Memory: 21729280

Adding a fixed value constraint makes the model infeasible, which is discovered within the timeout.
I00-1 -1:-1:-1.037353 20680 utilities.cc:554] Model has:
I00-1 -1:-1:-1.083984 20680 utilities.cc:555]   - 15 constraints.
I00-1 -1:-1:-1.120605 20680 utilities.cc:557]     * 7 Equal
I00-1 -1:-1:-1.385253 20680 utilities.cc:557]     * 4 VarValueWatcher
I00-1 -1:-1:-1.420654 20680 utilities.cc:557]     * 4 VarBoundWatcher
I00-1 -1:-1:-1.695068 20680 utilities.cc:559]   - 16 integer variables.
I00-1 -1:-1:-1.730712 20680 utilities.cc:560]   - 6 integer expressions.
I00-1 -1:-1:-1.005859 20680 utilities.cc:562]     * 6 Max
I00-1 -1:-1:-1.041259 20680 utilities.cc:564]   - 4 expressions casted into variables.
I00-1 -1:-1:-1.311279 20680 utilities.cc:565]   - 0 interval variables.
I00-1 -1:-1:-1.346679 20680 utilities.cc:566]   - 0 sequence variables.
I00-1 -1:-1:-1.042236 20680 utilities.cc:567]   - 0 model extensions.

Limit reached: False

Solver:Solver(name = "Test", state = NO_MORE_SOLUTIONS, branches = 48, fails = 25, decisions = 24, delayed demon runs = 0, var demon runs = 81, normal demon runs = 106, Run time = 4 ms)
State: 4
Number of solutions: 0
WallTime: 4 ms
Failures: 25
Branches: 48
Memory: 23535616

With more variables and a single phase, the specified timeout is reached and respected.
I00-1 -1:-1:-1.677978 20680 utilities.cc:554] Model has:
I00-1 -1:-1:-1.729248 20680 utilities.cc:555]   - 31 constraints.
I00-1 -1:-1:-1.815185 20680 utilities.cc:557]     * 15 Equal
I00-1 -1:-1:-1.108886 20680 utilities.cc:557]     * 8 VarBoundWatcher
I00-1 -1:-1:-1.417480 20680 utilities.cc:557]     * 8 VarValueWatcher
I00-1 -1:-1:-1.711669 20680 utilities.cc:559]   - 32 integer variables.
I00-1 -1:-1:-1.795654 20680 utilities.cc:560]   - 14 integer expressions.
I00-1 -1:-1:-1.082031 20680 utilities.cc:562]     * 14 Max
I00-1 -1:-1:-1.383789 20680 utilities.cc:564]   - 8 expressions casted into variables.
I00-1 -1:-1:-1.677734 20680 utilities.cc:565]   - 0 interval variables.
I00-1 -1:-1:-1.756347 20680 utilities.cc:566]   - 0 sequence variables.
I00-1 -1:-1:-1.041503 20680 utilities.cc:567]   - 0 model extensions.

Limit reached: True

Solver:Solver(name = "Test", state = NO_MORE_SOLUTIONS, branches = 380487, fails = 190247, decisions = 190246, delayed demon runs = 0, var demon runs = 486195, normal demon runs = 338274, Run time = 1000 ms)
State: 4
Number of solutions: 0
WallTime: 1009 ms
Failures: 190247
Branches: 380487
Memory: 54538240

With more variables and a single phase but without the fixed value constraint, the specified timeout is reached and respected.
I00-1 -1:-1:-1.773681 20680 utilities.cc:554] Model has:
I00-1 -1:-1:-1.585449 20680 utilities.cc:555]   - 34 constraints.
I00-1 -1:-1:-1.150146 20680 utilities.cc:557]     * 16 Equal
I00-1 -1:-1:-1.103515 20680 utilities.cc:557]     * 9 VarBoundWatcher
I00-1 -1:-1:-1.640869 20680 utilities.cc:557]     * 9 VarValueWatcher
I00-1 -1:-1:-1.114013 20680 utilities.cc:559]   - 36 integer variables.
I00-1 -1:-1:-1.722412 20680 utilities.cc:560]   - 16 integer expressions.
I00-1 -1:-1:-1.125976 20680 utilities.cc:562]     * 16 Max
I00-1 -1:-1:-1.566894 20680 utilities.cc:564]   - 9 expressions casted into variables.
I00-1 -1:-1:-1.949462 20680 utilities.cc:565]   - 0 interval variables.
I00-1 -1:-1:-1.398681 20680 utilities.cc:566]   - 0 sequence variables.
I00-1 -1:-1:-1.147460 20680 utilities.cc:567]   - 0 model extensions.

Solution 1:
Var000 = 0
Var001 = 0
Var002 = 0
Var003 = 0
Var004 = 0
Var005 = 0
Var006 = 0
Var007 = 0
Var008 = 0

Solution 2:
Var000 = 1
Var001 = 1
Var002 = 1
Var003 = 1
Var004 = 1
Var005 = 1
Var006 = 1
Var007 = 1
Var008 = 1

Limit reached: True

Solver:Solver(name = "Test", state = NO_MORE_SOLUTIONS, branches = 322746, fails = 161376, decisions = 161377, delayed demon runs = 0, var demon runs = 412464, normal demon runs = 287075, Run time = 1000 ms)
State: 4
Number of solutions: 2
WallTime: 1003 ms
Failures: 161376
Branches: 322746
Memory: 56160256

But without the fixed value constraint and multiple phases, after finding two solutions the timeout is exceeded.
I00-1 -1:-1:-1.473388 20680 utilities.cc:554] Model has:
I00-1 -1:-1:-1.527587 20680 utilities.cc:555]   - 34 constraints.
I00-1 -1:-1:-1.794433 20680 utilities.cc:557]     * 16 Equal
I00-1 -1:-1:-1.049072 20680 utilities.cc:557]     * 9 VarBoundWatcher
I00-1 -1:-1:-1.302734 20680 utilities.cc:557]     * 9 VarValueWatcher
I00-1 -1:-1:-1.554931 20680 utilities.cc:559]   - 36 integer variables.
I00-1 -1:-1:-1.807128 20680 utilities.cc:560]   - 16 integer expressions.
I00-1 -1:-1:-1.059082 20680 utilities.cc:562]     * 16 Max
I00-1 -1:-1:-1.311523 20680 utilities.cc:564]   - 9 expressions casted into variables.
I00-1 -1:-1:-1.636962 20680 utilities.cc:565]   - 0 interval variables.
I00-1 -1:-1:-1.978027 20680 utilities.cc:566]   - 0 sequence variables.
I00-1 -1:-1:-1.283935 20680 utilities.cc:567]   - 0 model extensions.

Solution 1:
Var000 = 0
Var001 = 0
Var002 = 0
Var003 = 0
Var004 = 0
Var005 = 0
Var006 = 0
Var007 = 0
Var008 = 0

Solution 2:
Var000 = 1
Var001 = 1
Var002 = 1
Var003 = 1
Var004 = 1
Var005 = 1
Var006 = 1
Var007 = 1
Var008 = 1

Limit reached: True

Solver:Solver(name = "Test", state = NO_MORE_SOLUTIONS, branches = 19916861, fails = 9958431, decisions = 9958431, delayed demon runs = 0, var demon runs = 25452882, normal demon runs = 17714434, Run time = 54222 ms)
State: 4
Number of solutions: 2
WallTime: 54224 ms
Failures: 9958431
Branches: 19916861
Memory: 41754624
Press any key to continue...

What did you expect to see In the last section, instead of running to 54222 ms, the solver should have stopped searching when 1000 ms was reached and report NO_MORE_SOLUTIONS:

What did you see instead? The solver kept searching until the entire search tree was visited and required 54222 s.

Make sure you include information that can help us debug (full error message, model Proto).

Anything else we should know about your project / environment

ChristopherHamkins commented 3 years ago

If I explicitly also add the limits to the single solution decision builder in method makePermutationDecisionBuilder(Solver solver) like this:

            SearchLimit limits = solver.MakeLimit(timeLimit_ms, long.MaxValue, long.MaxValue, long.MaxValue, true, true);
            DecisionBuilder singleSolutionDecisionBuilder = solver.MakeSolveOnce(restDecisionBuilder, limits);

The time limit is respected.

ChristopherHamkins commented 3 years ago

Reusing the same limits object in 

DecisionBuilder singleSolutionDecisionBuilder = solver.MakeSolveOnce(restDecisionBuilder, limits);

and in

solver.NewSearch(decisionBuilder, limits);

also leads to the time limit not being respected.