Error reported while running pyomo optimization with cbc solver and using timelimit

Question

I am trying to solve Optimisation problem with pyomo (Pyomo 5.3 (CPython 2.7.13 on Linux 3.10.0-514.26.2.el7.x86_64)) using CBC solver (Version: 2.9.8) and specifying a time limit in solver of 60 sec. The solver is getting a feasible solution (-1415.8392) but apparently not yet optimal (-1415.84) as you can see below.

After time limit ends model seemingly exits with an error code. I want to print or get values of all variables of feasible solution using CBC in specified time limit. Or is there any other way by which I can set, if Model gets 99% value of an Optimal solution, to exit and print the feasible solution.

The error code is posted below.

Cbc0004I Integer solution of -1415.8392 found after 357760 iterations and 29278 nodes (47.87 seconds)
Cbc0010I After 30000 nodes, 6350 on tree, -1415.8392 best solution, best possible -1415.84 (48.87 seconds)
Cbc0010I After 31000 nodes, 6619 on tree, -1415.8392 best solution, best possible -1415.84 (50.73 seconds)
Cbc0010I After 32000 nodes, 6984 on tree, -1415.8392 best solution, best possible -1415.84 (52.49 seconds)
Cbc0010I After 33000 nodes, 7384 on tree, -1415.8392 best solution, best possible -1415.84 (54.31 seconds)
Cbc0010I After 34000 nodes, 7419 on tree, -1415.8392 best solution, best possible -1415.84 (55.73 seconds)
Cbc0010I After 35000 nodes, 7824 on tree, -1415.8392 best solution, best possible -1415.84 (57.37 seconds)
Traceback (most recent call last):
  File "model_final.py", line 392, in 
    solver.solve(model, timelimit = 60*1, tee=True)
  File "/home/aditya/0r/lib/python2.7/site-packages/pyomo/opt/base/solvers.py", line 655, in solve
    default_variable_value=self._default_variable_value)
  File "/home/aditya/0r/lib/python2.7/site-packages/pyomo/core/base/PyomoModel.py", line 242, in load_from
    % str(results.solver.status))
ValueError: Cannot load a SolverResults object with bad status: error

When I run the model generated by pyomo manually using the same command-line parameters as pyomo /usr/bin/cbc -sec 60 -printingOptions all -import /tmp/tmpJK1ieR.pyomo.lp -import -stat=1 -solve -solu /tmp/tmpJK1ieR.pyomo.soln it seems to exit normally and also writes the solution as shown below.

Cbc0010I After 35000 nodes, 7824 on tree, -1415.8392 best solution, best possible -1415.84 (57.06 seconds)
Cbc0038I Full problem 205 rows 289 columns, reduced to 30 rows 52 columns
Cbc0010I After 36000 nodes, 8250 on tree, -1415.8392 best solution, best possible -1415.84 (58.73 seconds)
Cbc0020I Exiting on maximum time
Cbc0005I Partial search - best objective -1415.8392 (best possible -1415.84), took 464553 iterations and 36788 nodes (60.11 seconds)
Cbc0032I Strong branching done 15558 times (38451 iterations), fathomed 350 nodes and fixed 2076 variables
Cbc0035I Maximum depth 203, 5019 variables fixed on reduced cost
Cbc0038I Probing was tried 31933 times and created 138506 cuts of which 0 were active after adding rounds of cuts (4.431 seconds)
Cbc0038I Gomory was tried 30898 times and created 99534 cuts of which 0 were active after adding rounds of cuts (4.855 seconds)
Cbc0038I Knapsack was tried 30898 times and created 12926 cuts of which 0 were active after adding rounds of cuts (8.271 seconds)
Cbc0038I Clique was tried 100 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.000 seconds)
Cbc0038I MixedIntegerRounding2 was tried 30898 times and created 13413 cuts of which 0 were active after adding rounds of cuts (3.652 seconds)
Cbc0038I FlowCover was tried 100 times and created 4 cuts of which 0 were active after adding rounds of cuts (0.019 seconds)
Cbc0038I TwoMirCuts was tried 30898 times and created 15292 cuts of which 0 were active after adding rounds of cuts (2.415 seconds)
Cbc0038I Stored from first was tried 30898 times and created 15734 cuts of which 0 were active after adding rounds of cuts (0.000 seconds)
Cbc0012I Integer solution of -1411.9992 found by Reduced search after 467825 iterations and 36838 nodes (60.12 seconds)
Cbc0020I Exiting on maximum time
Cbc0005I Partial search - best objective -1411.9992 (best possible -1415.4522), took 467825 iterations and 36838 nodes (60.12 seconds)
Cbc0032I Strong branching done 476 times (1776 iterations), fathomed 1 nodes and fixed 18 variables
Cbc0035I Maximum depth 21, 39 variables fixed on reduced cost
Cuts at root node changed objective from -1484.12 to -1415.45
Probing was tried 133 times and created 894 cuts of which 32 were active after adding rounds of cuts (0.060 seconds)
Gomory was tried 133 times and created 1642 cuts of which 0 were active after adding rounds of cuts (0.047 seconds)
Knapsack was tried 133 times and created 224 cuts of which 0 were active after adding rounds of cuts (0.083 seconds)
Clique was tried 100 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.001 seconds)
MixedIntegerRounding2 was tried 133 times and created 163 cuts of which 0 were active after adding rounds of cuts (0.034 seconds)
FlowCover was tried 100 times and created 5 cuts of which 0 were active after adding rounds of cuts (0.026 seconds)
TwoMirCuts was tried 133 times and created 472 cuts of which 0 were active after adding rounds of cuts (0.021 seconds)
ImplicationCuts was tried 25 times and created 41 cuts of which 0 were active after adding rounds of cuts (0.003 seconds)

Result - Stopped on time limit

Objective value:                -1411.99922848
Lower bound:                    -1415.452
Gap:                            0.00
Enumerated nodes:               36838
Total iterations:               467825
Time (CPU seconds):             60.13
Time (Wallclock seconds):       60.98

Total time (CPU seconds):       60.13   (Wallclock seconds):       61.01

The top few lines of the CBC solution file are:

Stopped on time - objective value -1411.99922848
      0 c_e_x1454_                         0                       0
      1 c_e_x1455_                         0                       0
      2 c_e_x1456_                         0                       0
      3 c_e_x1457_                         0                       0
      4 c_e_x1458_                         0                       0
      5 c_e_x1459_                         0                       0
      6 c_e_x1460_                         0                       0
      7 c_e_x1461_                         0                       0
      8 c_e_x1462_                         0                       0

Can anyone tell me how can I get these values without generating any error?

Thanks in advance.

Answer 1

You could try to set the bound gap tolerance such that it will accept the other answer. I'm surprised that the solver status is coming back with error if there is a feasible solution found. Could you print out the whole results object?

Answer 2

Created a pull request https://github.com/Pyomo/pyomo/pull/265 to address this issue.

For those who want the patch right away:

In file pyomo/solvers/plugins/solvers/CBCplugin.py

@@ -264,7 +264,8 @@ def _check_and_escape_options(options):
             cmd.append('-AMPL')

             if self._timelimit is not None and self._timelimit > 0.0:
-                cmd.extend(['-sec', str(self._timelimit)])
+                cmd.extend(['-sec', str(self._timelimit - 1 )])
+                cmd.extend(['-timeMode', "elapsed"])
             if "debug" in self.options:
                 cmd.extend(["-log","5"])
             for key, val in _check_and_escape_options(self.options):
@@ -276,7 +277,8 @@ def _check_and_escape_options(options):
                         #"-stat"])
         else:
             if self._timelimit is not None and self._timelimit > 0.0:
-                cmd.extend(['-sec', str(self._timelimit)])
+                cmd.extend(['-sec', str(self._timelimit - 1 )])
+                cmd.extend(['-timeMode', "elapsed"])
             if "debug" in self.options:
                 cmd.extend(["-log","5"])
             # these must go after options that take a value

The timelimit is set to 1 sec lower than provided option to ensure CBC process gets time to exit properly before the pyutilib.subprocess.processmngr checks the exit code. In my test runs the process manager checked the exit status at T+0.02 seconds and CBC process typically exited after T+0.1 seconds.

Also changed the CBC code to use the wallclock seconds from the default of CPU seconds as the process manager is also checking the same.