Originally posted by: Mambo12345

Good evening,

i would like to make my quadratic binary integer program faster so I used a Upper Cutoff value.
I calculatet the best solution which is 1056 for my problem and then i set the Upper Cutoff value as 2000, 1500 and even 1057. It takes much longer when I set the value 1057 where 1056 is the best solution. Can anyone please explain this ?

CPXPARAM_Output_CloneLog                         1
Found incumbent of value 57806.000000 after 0.00 sec. (0.50 ticks)
Warning:  Non-integral bounds for integer variables rounded.
Tried aggregator 1 time.
MIP Presolve eliminated 11 rows and 88 columns.
MIP Presolve added 13076 rows and 6538 columns.
Reduced MIP has 13099 rows, 6658 columns, and 26392 nonzeros.
Reduced MIP has 6658 binaries, 0 generals, 0 SOSs, and 0 indicators.
Presolve time = 0.02 sec. (8.08 ticks)
Probing time = 0.05 sec. (2.80 ticks)
Tried aggregator 1 time.
MIP Presolve eliminated 7196 rows and 658 columns.
Reduced MIP has 5903 rows, 6000 columns, and 17880 nonzeros.
Reduced MIP has 6000 binaries, 0 generals, 0 SOSs, and 0 indicators.
Presolve time = 0.03 sec. (18.28 ticks)
Probing time = 0.02 sec. (2.76 ticks)
Clique table members: 23.
MIP emphasis: balance optimality and feasibility.
MIP search method: dynamic search.
Parallel mode: deterministic, using up to 4 threads.
Root relaxation solution time = 0.03 sec. (10.69 ticks)

 

Zero-half cuts applied:  9

Root node processing (before b&c):
  Real time             =    1.17 sec. (647.39 ticks)
Parallel b&c, 4 threads:
  Real time             =   47.84 sec. (23668.26 ticks)
  Sync time (average)   =    2.95 sec.
  Wait time (average)   =    0.01 sec.
                          ------------
Total (root+branch&cut) =   49.02 sec. (24315.65 ticks)

And with the Upper Cutoff:

 

CPXPARAM_Output_CloneLog                         1
CPXPARAM_MIP_Tolerances_UpperCutoff              1057
Warning:  Non-integral bounds for integer variables rounded.
Tried aggregator 1 time.
MIP Presolve eliminated 11 rows and 88 columns.
MIP Presolve added 13076 rows and 6538 columns.
Reduced MIP has 13099 rows, 6658 columns, and 26392 nonzeros.
Reduced MIP has 6658 binaries, 0 generals, 0 SOSs, and 0 indicators.
Presolve time = 0.00 sec. (8.08 ticks)
Probing time = 0.03 sec. (2.80 ticks)
Tried aggregator 1 time.
MIP Presolve eliminated 7196 rows and 658 columns.
Reduced MIP has 5903 rows, 6000 columns, and 17880 nonzeros.
Reduced MIP has 6000 binaries, 0 generals, 0 SOSs, and 0 indicators.
Presolve time = 0.05 sec. (18.28 ticks)
Probing time = 0.02 sec. (2.23 ticks)
Clique table members: 23.
MIP emphasis: balance optimality and feasibility.
MIP search method: dynamic search.
Parallel mode: deterministic, using up to 4 threads.
Root relaxation solution time = 0.02 sec. (10.69 ticks)

 

Zero-half cuts applied:  2
Gomory fractional cuts applied:  1

Root node processing (before b&c):
  Real time             =    1.02 sec. (607.78 ticks)
Parallel b&c, 4 threads:
  Real time             =   55.00 sec. (26086.65 ticks)
  Sync time (average)   =    3.45 sec.
  Wait time (average)   =    0.00 sec.
                          ------------
Total (root+branch&cut) =   56.02 sec. (26694.44 ticks)

Best regards !

Originally posted by: EdKlotz

I doubt the upper cutoff value has anything to do with the differences in time in the two logs you posted.   The upper cutoff primarily comes into play during the tree search, yet in the above two logs CPLEX appears to find the optimal solution at the root node, before any tree search starts.   While is is true that an upper cutoff value can be used during the probing process, the logs indicate that probing takes only .02 of a second.   And all indications are that the presolved model that CPLEX solves in each case is the same size.  

If I had to guess based on the logs you provided, I'd say either

1)  The cutoff value forced the root node heuristics that ultimately found the optimal solution to work harder, resulting in additional run time.

or

2)  The difference in run time occurred because during the cutoff run something else was consuming CPU core resources, resulting in different times.

Here are a few things you can do to narrow things down.   First, try the same runs again with the MIP display parameter to 5, so we can get more information about exactly how CPLEX found the optimal solution.   With the output in the logs you provided, we can really only tell what happened up to the initial root node LP solve, but times seem very similar up to that point.

Second, do the same tests with the threads parameter set to 1.   It would be interesting to see if you can reproduce this difference with parallelism and the associated threads initializations and synchronizations removed from consideration.

Third, do  the runs with and without the cutoff value with say 5 different random seeds to check if your results are consistent.   Do that test with both one and four threads.   To do this, just read in the LP or SAV file of the model into interactive CPLEX, then use the 'tools runseeds' command.

Originally posted by: Mambo12345

Thank you very much for your quick answer Ed Klotz,

I already did it with 4 different values and it always leads to a higher time when I set a very good upper Cutoff. In one case it took 69 seconds with upper cutoff and just 37 without upper cutoff and I did this 3 times because I also thought that something else was consuming CPU core resources.
That is the output when I set the display parameter to 'iter' and I have no upper cutoff:
When I set it to 5 it is way to much output, I can not post it because it is to long, but I hope you can see something out of this:

CPXPARAM_Output_CloneLog                         1
Found incumbent of value 57806.000000 after 0.00 sec. (0.50 ticks)
Warning:  Non-integral bounds for integer variables rounded.
Tried aggregator 1 time.
MIP Presolve eliminated 11 rows and 88 columns.
MIP Presolve added 13076 rows and 6538 columns.
Reduced MIP has 13099 rows, 6658 columns, and 26392 nonzeros.
Reduced MIP has 6658 binaries, 0 generals, 0 SOSs, and 0 indicators.
Presolve time = 0.00 sec. (8.08 ticks)
Probing time = 0.03 sec. (2.80 ticks)
Tried aggregator 1 time.
MIP Presolve eliminated 7196 rows and 658 columns.
Reduced MIP has 5903 rows, 6000 columns, and 17880 nonzeros.
Reduced MIP has 6000 binaries, 0 generals, 0 SOSs, and 0 indicators.
Presolve time = 0.03 sec. (18.28 ticks)
Probing time = 0.03 sec. (2.76 ticks)
Clique table members: 23.
MIP emphasis: balance optimality and feasibility.
MIP search method: dynamic search.
Parallel mode: deterministic, using up to 4 threads.
Root relaxation solution time = 0.03 sec. (10.69 ticks)

        Nodes                                         Cuts/
   Node  Left     Objective  IInf  Best Integer    Best Bound    ItCnt     Ga

*     0+    0                         1354.0000        0.0000           100.00
      0     0        0.0000    16     1354.0000        0.0000       27  100.00
      0     0        0.0000    16     1354.0000      Cuts: 60       58  100.00
*     0+    0                         1146.0000        0.0000           100.00
      0     0        0.0000    16     1146.0000      Cuts: 54      101  100.00
      0     2        0.0000    16     1146.0000        0.0000      101  100.00
Elapsed time = 1.25 sec. (649.97 ticks, tree = 0.02 M
, solutions =
)
*   139+   78                         1142.0000        0.0000           100.00
    170    81      549.7500    62     1142.0000        0.0000     6943  100.00
*   341+  231                         1136.0000        0.0000           100.00%
    383   253        cutoff           1136.0000        0.0000    12328  100.00%
*   455+  304                         1124.0000        0.0000           100.00%
*   570   372      integral     0     1120.0000        0.0000    20304  100.00%
    573   376        cutoff           1120.0000        0.0000    21620  100.00%
*   651   440      integral     0     1114.0000        0.0000    23535  100.00
*   798+  513                         1098.0000        0.0000           100.00%
    848   548      460.0000    52     1098.0000        0.0000    28296  100.00%
   1085   719      419.0000    36     1098.0000      180.0000    34049   83.61%
   1349   913      491.7143    55     1098.0000      245.0000    40280   77.69%
   1627  1097      825.0000    49     1098.0000      287.0000    46888   73.86
   1892  1232      915.3333    67     1098.0000      314.0000    52018   71.40%
   2143  1394        cutoff           1098.0000      338.0000    57851   69.22%
*  2365+ 1022                         1082.0000      378.0000            65.06
   2365  1023        0.0000    16     1082.0000      378.0000    65854   65.06
Elapsed time = 8.69 sec. (4298.29 ticks, tree = 21.07 M
, solutions =
)
   2439    51      648.6667    53     1082.0000      378.0000    69482   65.06
   2627   202      836.5000    36     1082.0000      378.0000    77581   65.06%
   2868   333      374.0000    38     1082.0000      378.0000    84419   65.06
   3186   616     1026.1429    57     1082.0000      378.0000    93145   65.06%
   3613   959     1190.0000    60     1082.0000      378.0000   101111   65.06%
*  4054+ 1254                         1074.0000      378.0000            64.80
   4127  1281      500.5455    75     1074.0000      378.0000   113120   64.80%
   4768  1838      724.0000    68     1074.0000      378.0000   129630   64.80%
   5378  2336        0.0000    16     1074.0000      378.0000   147038   64.80
   5878   282      387.6000    62     1074.0000      378.0000   171796   64.80%
   6646   855        cutoff           1074.0000      378.0000   202388   64.80%
Elapsed time = 30.88 sec. (15671.78 ticks, tree = 2.90 MB, solutions = 10)
   7414  1232      843.3333    66     1074.0000      482.0000   231404   55.12%
*  7543+ 1289                         1056.0000      501.0000            52.56%
   8301  1608        cutoff           1056.0000      546.0000   256637   48.30%
   9134  1820     1023.5000    59     1056.0000      630.0000   290322   40.34
   9813  1917      934.0000    54     1056.0000      705.0000   316191   33.24%
  10540  1941      943.0000    41     1056.0000      753.3333   338133   28.66
  11280  1857      958.4000    76     1056.0000      792.2857   362408   24.97%
  12057  1686     1009.3333    56     1056.0000      830.0000   389266   21.40%
  12995  1184        cutoff           1056.0000      890.0000   418770   15.72%
  14295   142        cutoff           1056.0000     1010.0000   442320    4.36%
Zero-half cuts applied:  9

Root node processing (before b&c):
  Real time             =    1.27 sec. (647.39 ticks)
Parallel b&c, 4 threads:
  Real time             =   48.20 sec. (23668.26 ticks)
  Sync time (average)   =    3.17 sec.
  Wait time (average)   =    0.01 sec.
                          ------------
Total (root+branch&cut) =   49.47 sec. (24315.65 ticks)

And now with the Upper Cutoff of 1057 while 1056 is the solution:

CPXPARAM_Output_CloneLog                         1
CPXPARAM_MIP_Tolerances_UpperCutoff              1057
Warning:  Non-integral bounds for integer variables rounded.
Tried aggregator 1 time.
MIP Presolve eliminated 11 rows and 88 columns.
MIP Presolve added 13076 rows and 6538 columns.
Reduced MIP has 13099 rows, 6658 columns, and 26392 nonzeros.
Reduced MIP has 6658 binaries, 0 generals, 0 SOSs, and 0 indicators.
Presolve time = 0.02 sec. (8.08 ticks)
Probing time = 0.03 sec. (2.80 ticks)
Tried aggregator 1 time.
MIP Presolve eliminated 7196 rows and 658 columns.
Reduced MIP has 5903 rows, 6000 columns, and 17880 nonzeros.
Reduced MIP has 6000 binaries, 0 generals, 0 SOSs, and 0 indicators.
Presolve time = 0.05 sec. (18.28 ticks)
Probing time = 0.02 sec. (2.23 ticks)
Clique table members: 23.
MIP emphasis: balance optimality and feasibility.
MIP search method: dynamic search.
Parallel mode: deterministic, using up to 4 threads.
Root relaxation solution time = 0.02 sec. (10.69 ticks)

        Nodes                                         Cuts/
   Node  Left     Objective  IInf  Best Integer    Best Bound    ItCnt     Ga

      0     0        0.0000    16                      0.0000       27        
      0     0        0.0000    16                    Cuts: 60       58        
      0     0        0.0000    16                    Cuts: 54      101        
      0     2        0.0000    16                      0.0000      101        
Elapsed time = 1.16 sec. (610.47 ticks, tree = 0.02 M
, solutions =
)
    160    90        0.0000    16                      0.0000     6204         
    355   219      421.0000    28                      0.0000    10820         
    593   363        cutoff                            0.0000    18084         
    885   610      627.5556    88                    148.0000    25374         
   1196   769      836.7500    60                    205.0000    32198         
*  1317   864      integral     0     1056.0000      262.0000    36352   75.19
   1505   964      377.3333    40     1056.0000      282.0000    39668   73.30
   1725  1131     1035.5000    36     1056.0000      326.0000    46980   69.13
   2020  1309      652.3333    51     1056.0000      384.0000    57454   63.64%
   2324  1417      790.0000    40     1056.0000      414.0000    64832   60.80%
   3604  2028      990.6667    66     1056.0000      517.5556    97473   50.99
Elapsed time = 7.98 sec. (3724.32 ticks, tree = 8.61 M
, solutions =
)
   3605  2104        0.0000    16     1056.0000      529.0000   100420   49.91
   3641   287      512.4078    71     1056.0000      529.0000   102387   49.91%
   3769   107      932.4000    75     1056.0000      529.0000   105549   49.91
   3909   195        cutoff           1056.0000      529.0000   110954   49.91%
   4102   340      345.6667    39     1056.0000      529.0000   118224   49.91%
   4328   473      557.4615    70     1056.0000      529.0000   122166   49.91
   4612   687      462.0000    70     1056.0000      529.0000   133232   49.91
   5147   991      968.6667    70     1056.0000      529.0000   145989   49.91%
   5721  1396      373.3333    54     1056.0000      529.0000   166098   49.91%
   6172  1630      851.0000    51     1056.0000      529.0000   183443   49.91%
Elapsed time = 29.70 sec. (13791.40 ticks, tree = 5.21 MB, solutions = 1)
   6776  1891      837.0000    63     1056.0000      529.0000   202425   49.91%
   7352  2180      770.8571    72     1056.0000      529.0000   220671   49.91
   7985  2367      863.6667    57     1056.0000      532.6667   238801   49.56%
   8667  2665        cutoff           1056.0000      571.0000   267420   45.93%
   9425  2851        cutoff           1056.0000      617.0000   292159   41.57%
  10050  2927      999.3333    56     1056.0000      652.0000   310597   38.26%
  10697  2896      935.3333    50     1056.0000      692.0000   337298   34.47%
  11565  2910      944.0000    60     1056.0000      736.5000   361575   30.26
  12292  2828      914.6667    60     1056.0000      774.0000   385275   26.70%
  13082  2632        cutoff           1056.0000      806.0000   412050   23.67%
Elapsed time = 51.30 sec. (23338.86 ticks, tree = 14.85 MB, solutions = 1)
  13943  2303      996.0000    45     1056.0000      841.2000   438090   20.34%
  14914  1765        cutoff           1056.0000      888.0000   464825   15.91%
  16013   853        cutoff           1056.0000      944.0000   492898   10.61%
Zero-half cuts applied:  2
Gomory fractional cuts applied:  1

Root node processing (before b&c):
  Real time             =    1.14 sec. (607.78 ticks)
Parallel b&c, 4 threads:
  Real time             =   57.50 sec. (26086.65 ticks)
  Sync time (average)   =    4.24 sec.
  Wait time (average)   =    0.00 sec.
                          ------------
Total (root+branch&cut) =   58.64 sec. (26694.44 ticks)

I dont understand what I should do with one or four threads ? I have never seen that before and where can I find this LP or SAV file ?
But I have tried it with different data and it is always the result that it takes longer with upper cutoff.

Best regards and thank you so much for your help !

Originally posted by: EdKlotz

Yes, that level of node log info provides some traction.   Based on that, I would say the difference in performance, which is only about 15-20%, could be attributed to the following factors:

• The reasoning behind the benefit of a cutoff value is that branch and bound won't waste time exploring nodes relaxation objective values above the cutoff value.   But if we look at the node log without the cutoff value, we see very few node LPs with objectives at 1057 or above.   I see this one:                                                                                        3613   959     1190.0000    60     1082.0000      378.0000   101111   65.06%                                                                                                                                                                    but otherwise, all the node relaxation objectives are < 1057.   So the pruning benefit seems quite minimal
• The heuristics all fail with the cutoff set at 1057.   The actually have to work longer when they fail than when they succeed, which they do without the cutoff (because they are able to find worse solutions.
• The path taken is completely different, and the node and iterations counts for the run with the cutoff are 10-15% higher.  

Putting this all together, the decline in performance is not that large, and there are some reasonable explanations.   We actually did some tests with CPLEX where we gave it the optimal solution for various MIPs as an advanced start.   While this frequently helped performance, sometimes it didn't help at all, or performance even degraded.   So if it can happen with the optimal solution, provided, it can certainly happen with a near optimal cutoff.

Overall, given the size of the model, I'd say solve times in the 45-60 second range a reasonable, but some potential for improved performance does exist.   But these are more likely to be attained by trying non default parameter settings or tightening the formulation.   For more on that, see the technote at

https://www-01.ibm.com/support/docview.wss?uid=swg21400023

Regarding

I dont understand what I should do with one or four threads ? I have never seen that before and where can I find this LP or SAV file ?
But I have tried it with different data and it is always the result that it takes longer with upper cutoff.

Any CPLEX API has the ability to export an LP or SAV file from the program that created the model.   So you add that to your program (e.g. call the exportModel methods available in C++ and Java, or something similar in the other APIs) to get this.   You create the LP or SAV file, you don't find it. And CPLEX allows you to set the threads limit to whatever you want.   However, based on the node logs you have provided, I don't think thread count is involved in the performance differences, so you probably can skip that test.

Originally posted by: Mambo12345

Thank you so much for all you advices and help !
It is amazing that you helped me and answered in such a short time.
I think that I understood the problem now and I see why this happened.

Best regards and all the best for you !