Inconsistency run time between python-mip and CBC command line

[RanAbram]

Hi Everybody,
Thanks for that great project!

I saw some inconsistency between python-mip and CBC command line in terms of run time.
I have a set-cover like problem which python-mip (latest version) solves in about 60 seconds of solver time with CBC.
When I save the problem to .mps and run it directly with CBC command line, I get the identical solution in about 18 seconds.

CBC command line results:

Result - Optimal solution found
Objective value:                1000735.38202685
Enumerated nodes:               6
Total iterations:               297
Time (CPU seconds):             17.56
Time (Wallclock seconds):       19.69
Total time (CPU seconds):       17.80   (Wallclock seconds):       19.97

python-mip results:

Cbc0001I Search completed - best objective 1000735.382055489, took 207 iterations and 4 nodes (61.62 seconds)
Cbc0032I Strong branching done 164 times (4559 iterations), fathomed 1 nodes and fixed 0 variables
Cbc0035I Maximum depth 2, 84766 variables fixed on reduced cost
Total time (CPU seconds):       59.41   (Wallclock seconds):       62.33

We didn't change the default value to any parameter..
It seems like while the command line version exits because it completed the search in those 18 seconds, the python version exits (after so much longer time) because it got "close enough" ("integer gap of 7.1747573 less than 1e-10 or 0.1%").

Any suggestions for why it might happen?
Are we missing something?

Thanks!

To Reproduce

1. Download the following file mip.mps.gz
2. Extract it
3. Run the following command: cbc mip.mps solve solu sol_mip.txt

Expected behavior
Same runtime for python-mip and CBC command line

Desktop (please complete the following information):

• Operating System, version: Mac, bigSur
• Python version: 3.7
• Python-MIP version (we recommend you to test with the latest version): latest version

Additional context

Few more logs from the CBC command line process:

Cbc0012I Integer solution of 1000735.4 found by rounding after 187 iterations and 3 nodes (17.23 seconds)
Cbc0001I Search completed - best objective 1000735.382026846, took 297 iterations and 6 nodes (17.39 seconds)
Cbc0032I Strong branching done 192 times (5251 iterations), fathomed 1 nodes and fixed 0 variables
Cbc0035I Maximum depth 2, 89345 variables fixed on reduced cost
Cuts at root node changed objective from 1.00073e+06 to 1.00073e+06
Probing was tried 9 times and created 14 cuts of which 0 were active after adding rounds of cuts (0.329 seconds)
Gomory was tried 5 times and created 4 cuts of which 0 were active after adding rounds of cuts (0.420 seconds)
Knapsack was tried 5 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.069 seconds)
Clique was tried 5 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.003 seconds)
MixedIntegerRounding2 was tried 9 times and created 2 cuts of which 0 were active after adding rounds of cuts (0.246 seconds)
FlowCover was tried 5 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.034 seconds)
TwoMirCuts was tried 1 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.090 seconds)
ZeroHalf was tried 5 times and created 8 cuts of which 0 were active after adding rounds of cuts (0.330 seconds)
Result - Optimal solution found
Objective value:                1000735.38202685
Enumerated nodes:               6
Total iterations:               297
Time (CPU seconds):             17.56
Time (Wallclock seconds):       19.69
Total time (CPU seconds):       17.80   (Wallclock seconds):       19.97

More logs for python-mip process:

Cbc0010I After 0 nodes, 1 on tree, 2000834.9 best solution, best possible 1000728.2 (56.94 seconds)
Cbc0010I After 1 nodes, 2 on tree, 2000834.9 best solution, best possible 1000728.2 (57.90 seconds)
Cbc0010I After 2 nodes, 3 on tree, 2000834.9 best solution, best possible 1000728.2 (60.39 seconds)
Cbc0012I Integer solution of 1000738.1 found by DiveCoefficient after 178 iterations and 3 nodes (60.76 seconds)
Cbc0016I Integer solution of 1000735.4 found by strong branching after 178 iterations and 3 nodes (60.79 seconds)
Cbc0011I Exiting as integer gap of 7.1747573 less than 1e-10 or 0.1%
Cbc0001I Search completed - best objective 1000735.382055489, took 207 iterations and 4 nodes (60.88 seconds)
Cbc0032I Strong branching done 164 times (4559 iterations), fathomed 1 nodes and fixed 0 variables
Cbc0035I Maximum depth 2, 84766 variables fixed on reduced cost
Total time (CPU seconds):       58.94   (Wallclock seconds):       61.53

[h-g-s]

Hi @RanAbram ,

These deviations (for more or less time) are expected in individual instances. The main reason is that python-mip uses some specific cbc git revisions for its releases. Also, binaries for the python-mip library were probably compiled with different options/gcc version than your cbc command line binary.

Does it means that python-mip library is slower than your cbc binary ? Probably not, as we can only conclude it by running experiments on a large set of instances. Many deviations for faster/slower executions are expected. Why ? This happens because MIP solvers are chaotic systems, they are extremely sensitive to the initial conditions. To know more about this topic I recomment the paper ˝Exploiting Erraticism in Search˝ (https://pubsonline.informs.org/doi/abs/10.1287/opre.2013.1231). A short explanation is that, in the beginning of the tree search there are many options on how to proceed and even though many options seem similar, they can have large impact on the total running time. For example, for branching, one solver may try to select always the most fractional variable. This criterion may be deterministic, but usually there many variables with the same fractional value in some fractional solution. At first sight, it may seem that the impact of selecting each one of these first may not be too influential, but it is.

In python-mip you can enter different random seeds for the solver to introduce small perturbations for the solver. You can easily see that even for the same instance you usually can obtain different running times.

If you observe that this slowdown is consistent in a large set of problems, it may be worth investigate it, otherwise this is an expected deviation.

Talking about large set of instances, can I add your mip to our set of test problems ?

Cheers