Originally posted by: StephanBeyer

Hi,

I added a dummy IloBoolVar into an continuous LP model to access features like SolveCallbacks
(see topic "Recommended way to feed an optimal solution to LP relaxation model").
To my surprise, I noticed that the runtime increased largely although no branch&cut is involved.

In both scenarios, CPLEX is bound to non-parallel mode and relaxations are computed using simplex.

CPLEX output without dummy variable (time ~4 seconds):

Tried aggregator 1 time.
LP Presolve eliminated 1956 rows and 1958 columns.
Aggregator did 2048 substitutions.
Reduced LP has 41518 rows, 37306 columns, and 141390 nonzeros.
Presolve time = 0.05 sec. (42.26 ticks)
Initializing dual steep norms . . .

Iteration log . . .
Iteration:     1   Dual objective     =             0.000000
Perturbation started.
Iteration:   101   Dual objective     =             0.000000
Iteration:   653   Dual objective     =             0.000021
Iteration:  1374   Dual objective     =             0.000041
Iteration:  2075   Dual objective     =             0.000058
Iteration:  2754   Dual objective     =             0.000073
Iteration:  3374   Dual objective     =            82.000076
Iteration:  3970   Dual objective     =            82.000086
Iteration:  4542   Dual objective     =            82.000099
Iteration:  5109   Dual objective     =            82.000111
Iteration:  5674   Dual objective     =            84.000112
Iteration:  6226   Dual objective     =           133.000106
Iteration:  6793   Dual objective     =           192.000123
Iteration:  7312   Dual objective     =           192.000133
Iteration:  7818   Dual objective     =           215.000138
Iteration:  8327   Dual objective     =           260.000094
Iteration:  8820   Dual objective     =           271.000120
Iteration:  9247   Dual objective     =           271.000130
Iteration:  9700   Dual objective     =           287.750145
Iteration: 10180   Dual objective     =           294.000144
Iteration: 10713   Dual objective     =           319.000151
Iteration: 11230   Dual objective     =           324.333487
Iteration: 11745   Dual objective     =           334.000140
Iteration: 12223   Dual objective     =           352.000093
Iteration: 12724   Dual objective     =           360.000124
Iteration: 13249   Dual objective     =           365.000146
Iteration: 13701   Dual objective     =           371.333474
Iteration: 14198   Dual objective     =           399.500136
Iteration: 14721   Dual objective     =           404.666814
Iteration: 15158   Dual objective     =           404.666829
Iteration: 15653   Dual objective     =           406.666849
Iteration: 16092   Dual objective     =           410.666860
Iteration: 16548   Dual objective     =           410.666876
Iteration: 17021   Dual objective     =           418.000191
Iteration: 17460   Dual objective     =           426.000228
Iteration: 17861   Dual objective     =           435.125195
Iteration: 18286   Dual objective     =           444.666876
Iteration: 18694   Dual objective     =           452.000223
Iteration: 19126   Dual objective     =           452.500133
Iteration: 19552   Dual objective     =           461.800166
Iteration: 19964   Dual objective     =           463.000212
Iteration: 20348   Dual objective     =           466.000235
Iteration: 20748   Dual objective     =           466.000248
Iteration: 21162   Dual objective     =           466.000257
Iteration: 21541   Dual objective     =           466.000273
Iteration: 21990   Dual objective     =           467.000269
Iteration: 22409   Dual objective     =           468.000273
Iteration: 22817   Dual objective     =           469.428846
Iteration: 23239   Dual objective     =           469.500289
Iteration: 23685   Dual objective     =           469.500302
Iteration: 24133   Dual objective     =           469.500313
Iteration: 24502   Dual objective     =           469.500320
Iteration: 24995   Dual objective     =           469.500327
Iteration: 25480   Dual objective     =           469.500334
Iteration: 25931   Dual objective     =           469.500339
Removing perturbation.

CPLEX output with dummy variable (time ~15 sec):

Tried aggregator 2 times.
MIP Presolve eliminated 1956 rows and 1958 columns.
Aggregator did 2048 substitutions.
Reduced MIP has 41518 rows, 37306 columns, and 141390 nonzeros.
Reduced MIP has 0 binaries, 0 generals, 0 SOSs, and 0 indicators.
Presolve time = 0.07 sec. (72.55 ticks)
Tried aggregator 1 time.
Reduced MIP has 41518 rows, 37306 columns, and 141390 nonzeros.
Reduced MIP has 0 binaries, 0 generals, 0 SOSs, and 0 indicators.
Presolve time = 0.12 sec. (64.12 ticks)
Initializing dual steep norms . . .

Iteration log . . .
Iteration:     1   Dual objective     =             0.000000
Perturbation started.
Iteration:   101   Dual objective     =             0.000000
Iteration:   623   Dual objective     =             0.000021
Iteration:  1380   Dual objective     =             0.000041
Iteration:  2089   Dual objective     =             0.000058
Iteration:  2759   Dual objective     =            82.000062
Iteration:  3387   Dual objective     =            82.000075
Iteration:  3991   Dual objective     =            82.000088
Iteration:  4556   Dual objective     =           131.000085
Iteration:  5137   Dual objective     =           133.000089
Iteration:  5683   Dual objective     =           185.000104
Iteration:  6190   Dual objective     =           203.000126
Iteration:  6675   Dual objective     =           227.000125
Iteration:  7197   Dual objective     =           227.000142
Iteration:  7671   Dual objective     =           235.500140
Iteration:  8156   Dual objective     =           248.166777
Iteration:  8629   Dual objective     =           270.833429
Iteration:  9076   Dual objective     =           282.166762
Iteration:  9535   Dual objective     =           283.833447
Iteration:  9965   Dual objective     =           283.833453
Iteration: 10369   Dual objective     =           283.833461
Iteration: 10793   Dual objective     =           283.833466
Iteration: 11246   Dual objective     =           283.833475
Iteration: 11706   Dual objective     =           290.333472
Iteration: 12147   Dual objective     =           303.333469
Iteration: 12558   Dual objective     =           303.333476
Iteration: 12961   Dual objective     =           303.333482
Iteration: 13373   Dual objective     =           319.533504
Iteration: 13769   Dual objective     =           328.276352
Iteration: 14142   Dual objective     =           336.832339
Iteration: 14537   Dual objective     =           354.819755
Iteration: 14881   Dual objective     =           358.813724
Iteration: 15261   Dual objective     =           370.420619
Iteration: 15625   Dual objective     =           375.390801
Iteration: 15995   Dual objective     =           383.993273
Iteration: 16384   Dual objective     =           399.471044
Iteration: 16765   Dual objective     =           399.686055
Iteration: 17145   Dual objective     =           399.904288
Iteration: 17476   Dual objective     =           408.069698
Iteration: 17817   Dual objective     =           411.041766
Iteration: 18120   Dual objective     =           413.604592
Iteration: 18425   Dual objective     =           420.022654
Iteration: 18780   Dual objective     =           430.695467
Iteration: 19088   Dual objective     =           434.683095
Iteration: 19382   Dual objective     =           439.321608
Iteration: 19705   Dual objective     =           439.643045
Iteration: 20010   Dual objective     =           440.753833
Iteration: 20302   Dual objective     =           445.368600
Iteration: 20586   Dual objective     =           447.398866
Iteration: 20859   Dual objective     =           453.413375
Iteration: 21168   Dual objective     =           453.413385
Iteration: 21459   Dual objective     =           453.413400
Iteration: 21741   Dual objective     =           456.643068
Iteration: 22061   Dual objective     =           457.426472
Iteration: 22378   Dual objective     =           458.500156
Iteration: 22638   Dual objective     =           459.333699
Iteration: 22938   Dual objective     =           459.470812
Iteration: 23241   Dual objective     =           460.670266
Iteration: 23545   Dual objective     =           461.423322
Iteration: 23834   Dual objective     =           461.468007
Iteration: 24148   Dual objective     =           461.559104
Iteration: 24431   Dual objective     =           462.250271
Iteration: 24690   Dual objective     =           462.250282
Iteration: 24955   Dual objective     =           462.541966
Iteration: 25230   Dual objective     =           462.750290
Iteration: 25516   Dual objective     =           462.750298
Iteration: 25793   Dual objective     =           462.889205
Iteration: 26053   Dual objective     =           462.889216
Iteration: 26317   Dual objective     =           462.889223
Iteration: 26576   Dual objective     =           463.391642
Iteration: 26833   Dual objective     =           463.391653
Iteration: 27122   Dual objective     =           463.810885
Iteration: 27425   Dual objective     =           467.329901
Iteration: 27758   Dual objective     =           467.391702
Iteration: 28049   Dual objective     =           468.105511
Iteration: 28302   Dual objective     =           468.105522
Iteration: 28630   Dual objective     =           468.857002
Iteration: 28932   Dual objective     =           469.171153
Iteration: 29252   Dual objective     =           469.500360
Iteration: 29578   Dual objective     =           469.500365
Elapsed time = 14.71 sec. (10000.15 ticks, 29737 iterations)
Removing perturbation.
Root relaxation solution time = 14.73 sec. (10016.89 ticks)

        Nodes                                         Cuts/
   Node  Left     Objective  IInf  Best Integer    Best Bound    ItCnt     Gap         Variable B NodeID Parent  Depth

*     0     0      integral     0      469.5000      469.5000    29741    0.00%                        0             0
Elapsed time = 14.96 sec. (10191.81 ticks, tree = 0.00 MB, solutions = 1)
Found incumbent of value 469.500000 after 14.96 sec. (10191.81 ticks)

Root node processing (before b&c):
  Real time             =   14.96 sec. (10193.24 ticks)
Sequential b&c:
  Real time             =    0.00 sec. (0.00 ticks)
                          ------------
Total (root+branch&cut) =   14.96 sec. (10193.24 ticks)

Do you have an idea what causes the difference and if it is possible to fix that by setting the right parameters?

Thanks,
  Stephan

EDIT: To make clear what I mean by dummy variable:

IloBoolVar dummy(env);

IloExpr objective(env);

...

objective += dummy;

And in the pure relaxation it is a IloNumVar dummy(env) [just to make sure we have the same number of variables.]

Can you please set CPX_PARAM_MIPDISPLAY to 4 and repeat the run with the dummy boolean variable? With the display level set to 4 you will also see the log output of the initial root LP solve. Maybe this sheds some light on what is going on.

Originally posted by: StephanBeyer

Thanks! I updated the original post. (I tried to reply but it was considered to be spam.)

One can clearly see that the reduced LP and reduced MIP are the same. Nonetheless, the dual simplex for the MIP works different than for the LP. I go through the CPLEX parameters and see what I can set and fix for simplex to fix that.

Originally posted by: StephanBeyer

I went through the options. I learned that by default CPLEX outputs iteration information during simplex when a basis matrix has been refactored (whatever that means). We can see in the outputs that the refactoring takes place at different times for the case with and without dummy variable. Fixing that iteration number using IloCplex::Param::Simplex::Refactor did result in different times for different values, but the dummy variable MIP was still worse. Also fixing CPLEX's random seed changed things, but the problem stayed the same.

So the most interesting parameter I found was IloCplex::Param::Simplex::DGradient

My measurements for the different values of this parameter:

Interestingly, only for 0 (automatic choice), the pure relaxation (IloNumVar dummy) was much faster. For others, it was even worse or equally bad.

Moreover, I expected that the times of 0 would coincide with one time of 1, 2, 3, 4, or 5. For the MIP (IloBoolVar dummy), one could say that the automatic choice is 2. However, for the LP (IloNumVar dummy) the automatic choice is clearly none of the other ones.

That's where I am now. CPLEX's behavior looks even more mysteriously to me now.

Stephan

Originally posted by: RWunderling

A few comments:

1. MIP presolve can behave differently than LP presolve

2. CPLEX uses the random generator for perturbation, but also for other things in the code.  So when it comes to perturbing the problem the random generator may be in a different state causing the problem to be perturbed in a different way.

3. The automatic setting dynamically decides what strategy to use, while the other choices fix the strategy throughout the optimization.

All this is to say, that the results you are seeing are not really surprising.  You may try and limit such effects by turning off features and/or changing the model, but CPLEX will not guarantee that you get the same runs for the root LP of a mip as for the relaxed problem solved as an LP.

Originally posted by: StephanBeyer

Ok. That means, in turn, that it is equally likely that CPLEX behaves faster with MIP dummy variable on other problems? That would be ok. (I will try later.)

In general you cannot predict whether solving as MIP or LP is faster, I have seen either one being faster in practice. For some models MIP presolve finds more reductions than LP presolve and sometimes this really helps. But there is no general rule for that.

Also note that when solving as a MIP you will only get the primal solution vector. No duality information will be available.