RoutingModel.UpdateTimeLimit() sometimes not honored

[Ed MacDonald]

I wrote a little test jig to create solve a routing problem with test data input.  When testing with very large sets of nodes and constraints, it would run "forever" so I added the following which seems to work most of the time:

routing.UpdateTimeLimit(TimeOut);

Then I wrote a test jig to process a very large number of routing problems, some of them trivial, some more complex.  Invariably, after running for some minutes, processing seems to get stuck on one problem and never times out.  The process is consuming 100% of one CPU core so it appears it is still doing "stuff" but based on a heap dump it remains stuck in.  I don't have the native symbols (yet) so sorry I can't be more specific.

Google.OrTools.dll!Google.OrTools.ConstraintSolver.RoutingModel.Solve()

If I then run the exact same problem by itself, the timeout works as expected.  

Any thoughts?

Thanks,

-Ed

[Ed MacDonald]

I have my timeout set to 60 seconds.  I added a logging search monitor, and here are a few lines of output from one of the runs that got stuck:

[01:24:05] src/constraint_solver/search.cc:243: 739000 branches, 9000 ms, 369496 failures, tree pos=27/38/48 minref=4 max=62, limit = 15%

[01:24:05] src/constraint_solver/search.cc:243: 740000 branches, 9012 ms, 369996 failures, tree pos=28/41/53 minref=4 max=62, limit = 15%

[01:24:05] src/constraint_solver/search.cc:243: 741000 branches, -286122 ms, 370496 failures, tree pos=29/39/56 minref=4 max=62

[01:24:05] src/constraint_solver/search.cc:243: 742000 branches, -286109 ms, 370997 failures, tree pos=22/28/53 minref=4 max=62

Notice that the running time suddenly goes negative and the progress against the limit stops being reported.  

-Ed

[Ed MacDonald]

Adding this code...

SearchMonitor log = routing.solver().MakeSearchTrace("RoutingSolverTrace");
routing.AddSearchMonitor(log);

Produces the following output consistently when it gets stuck.

A bunch of these...

[00:57:44] src/constraint_solver/search.cc:314: RoutingSolverTrace BeginNextDecision(ComposeDecisionBuilder(RestoreAssignment, LocalSearch)) 

[00:57:44] src/constraint_solver/search.cc:318: RoutingSolverTrace EndNextDecision(ComposeDecisionBuilder(RestoreAssignment, LocalSearch), Decision) 

[00:57:44] src/constraint_solver/search.cc:324: RoutingSolverTrace ApplyDecision(Decision) 

[00:57:44] src/constraint_solver/search.cc:330: RoutingSolverTrace AfterDecision(Decision, 1) 

Then three lines like this...

[00:57:44] src/constraint_solver/search.cc:314: RoutingSolverTrace BeginNextDecision(ComposeDecisionBuilder(RestoreAssignment, LocalSearch)) 

[00:57:44] src/constraint_solver/search.cc:318: RoutingSolverTrace EndNextDecision(ComposeDecisionBuilder(RestoreAssignment, LocalSearch), NestedSolveDecision) 

[00:57:44] src/constraint_solver/search.cc:324: RoutingSolverTrace ApplyDecision(NestedSolveDecision) 

And then nothing.

-Ed

[smile-on]

I'd like to report same issue on timeout sometime not been respected. Using java wrappers from binary distribution google.ortools_v4.3.3802_win64. When run TSP with all default parameters on graphs with 30K+ nodes solver terminates much later then timeout been set. In my test timeout was set at 10 minutes and actual termination happend after 26 minutes. OR-tools library used just one core out of 4 and memory swapping has not been an issue too.

Must be something in C++ library hook that should check for timeout more often during the search.