Originally posted by: Pr.Sanlaville

Hello,

In a column generation context, I'm working with linear programs which seem to put CPLEX 12.6 into trouble.

Here's an example of a LP (75 000 * 130 000, 1 400 000 non zeros) which requires more than half an hour to solve on recent personal computers, using CPLEX 12.6.

Note that, this LP has columns with real coefficients, which may look like this : 2,001232000543.

Using numerical emphasis, the LP solution time decreased by a factor 2, but, it is still not good enough.

I spent a lot of time in the manual, and tryed to change different parameters, like feasibility tolerance, negative reduced cost tolerance, without success.

Another problem is LP re-optimization.

After one column is added to a LP from the small family, which is even smaller, its re-optimization, starting from last optimal basis, requires several minutes ...

How could we improve CPLEX performance on this problem ?

Best regards,

Xavier Schepler

PhD Student

Originally posted by: EdKlotz

In terms of starting the optimization from scratch, try using the barrier method with numerical emphasis enabled.    That sped up the solve time by almost a factor of 10 on my machine.   Unlike CPLEX's current simplex implementation, the barrier method benefits from multiple threads, so hopefully the machines you use have at least 4 threads.   Anything beyond 8-12 threads probably won't help much.

The barrier method won't help with re-optimization, since the current implementation doesn't make use of advanced start information the way the simplex methods do.   However, when you did the reoptimization, did you use primal simplex method rather than dual simplex?   That could make a difference. As long is zero is in the domain of the variable associated with the added column, the last optimal basis remains primal feasible, but typically is not dual  feasible.   So, even though primal simplex appears to perform much worse than dual simplex or barrier on the model starting from scratch, it may still yield the best performance starting from an advanced basis.   If you were using dual simplex, try primal simplex.   If you were already using primal simplex, please upload an iteration log of the time consuming run, or a SAV file of the model with the added column and the previous optimal basis (i.e. if you  call CPXwriteprob or IloCplex::exportModel after you have added the column but before the reoptimization, the SAV file will include the model and the basis statuses.

And finally, the problem statistics for your model indicate that it has 4 matrix coefficients on the order of 1e-9.   Do those values have legitimate meaning in the model, or did they arise from round off error in some calculation?   Based on a histogram of coefficients, I suspect the latter.   If so, try removing those from the model, setting them to zero instead.   If those are in any way involved in slowing the performance, zeroing them out may help.

Originally posted by: ND10_Xavier_Schepler

Thank you for the quick response.

I can not use the barrier method because it doesn't provide warm start at the moment.
Re-optimization is done with the primal simplex.

A first LP is built with a pool of about 4000 initial columns, which are dynamically generated.
At least one artificial variable is added to each constraints from a set (1 for <= or >=, 2 for =).
There are other "static" variables, which are not artificial variables, and which can not be dynamically generated.
This first LP is optimized, producing the following log :
 

LP Presolve eliminated 1182 rows and 1869 columns.
Reduced LP has 74173 rows, 247879 columns, and 1422204 nonzeros.
Presolve time = 6.99 sec. (230.25 ticks)
Initializing dual steep norms . . .

Iteration log . . .
Iteration:     1   Dual objective     =             0.000000
Perturbation started.
Iteration:   101   Dual objective     =             0.000000
Iteration:   701   Dual objective     =             0.005794
Iteration:  1980   Dual objective     =             0.025701
Iteration:  2316   Dual objective     =             0.028173
Iteration:  3222   Dual objective     =            10.527969
Iteration:  3582   Dual objective     =            10.530139
Iteration:  4500   Dual objective     =            10.541696
Iteration:  4763   Dual objective     =            10.544063
Iteration:  5537   Dual objective     =            10.553143
Iteration:  6333   Dual objective     =            10.560517
Iteration:  7109   Dual objective     =            10.566502
Iteration:  7901   Dual objective     =            10.571260
Iteration:  8723   Dual objective     =            10.578410
Iteration:  8962   Dual objective     =            10.580689
Iteration:  9619   Dual objective     =            10.586488
Iteration: 10339   Dual objective     =            10.593395
Iteration: 10782   Dual objective     =            10.596502
Iteration: 11222   Dual objective     =            10.601149
Iteration: 11626   Dual objective     =            10.604494
Iteration: 11997   Dual objective     =            10.606734
Removing perturbation.
Initializing dual steep norms . . .

Then, pricing occurs in the generators, and about 20 columns are added :

Initializing primal norms rowwise . . .
Initializing primal norms rowwise . . .
Elapsed time = 46.17 sec. (88001.33 ticks, 1 iterations)

Iteration log . . .
Iteration:     1    Objective     =            10.500000
Iteration:   208    Objective     =            10.500000
Iteration:   494    Objective     =            10.500001
Iteration:   769    Objective     =            10.486160
Iteration:  1060    Objective     =            10.288850
Iteration:  1411    Objective     =            10.196659
Iteration:  1715    Objective     =             8.067738
Iteration:  2082    Objective     =             7.694711
Iteration:  2393    Objective     =             5.899845
Elapsed time = 61.64 sec. (98001.55 ticks, 2428 iterations)
Iteration:  2668    Objective     =             4.224081
Iteration:  2913    Objective     =             2.588639
Iteration:  3178    Objective     =             0.372469
Iteration:  3462    Objective     =            -0.623480
Iteration:  3752    Objective     =            -2.432296
Iteration:  4045    Objective     =            -3.289308
Iteration:  4294    Objective     =            -3.365158
Iteration:  4537    Objective     =            -8.063074
Elapsed time = 77.45 sec. (108005.82 ticks, 4629 iterations)
Iteration:  4795    Objective     =            -9.981913
Iteration:  5045    Objective     =           -10.461467
Iteration:  5314    Objective     =           -14.549501
Iteration:  5566    Objective     =           -18.221994
Iteration:  5809    Objective     =           -24.034160
Iteration:  6096    Objective     =           -34.489039
Iteration:  6497    Objective     =           -55.949795
Iteration:  6732    Objective     =           -74.319547
Elapsed time = 93.47 sec. (118007.50 ticks, 6821 iterations)
Iteration:  7005    Objective     =           -81.033873
Iteration:  7264    Objective     =           -91.574650
Iteration:  7570    Objective     =          -116.054786
Iteration:  7949    Objective     =          -145.495679
Iteration:  8475    Objective     =          -184.531183
Iteration:  8909    Objective     =          -185.195253
Iteration:  9203    Objective     =          -187.326435
Iteration:  9485    Objective     =          -202.754360
Elapsed time = 109.98 sec. (128009.52 ticks, 9515 iterations)
Iteration:  9815    Objective     =          -221.292739
Iteration: 10170    Objective     =          -247.934521
Iteration: 10487    Objective     =          -267.552829
Iteration: 10838    Objective     =          -277.091640
Iteration: 11152    Objective     =          -281.711522
Iteration: 11480    Objective     =          -288.315786
Iteration: 11852    Objective     =          -307.427869
Iteration: 12480    Objective     =          -329.304324
Elapsed time = 126.27 sec. (138011.48 ticks, 12780 iterations)
Iteration: 13132    Objective     =          -353.750482
Iteration: 13496    Objective     =          -364.626194
Iteration: 13803    Objective     =          -372.886339
Iteration: 14158    Objective     =          -386.714972
Iteration: 14477    Objective     =          -399.821621
Iteration: 14846    Objective     =          -415.933004
Iteration: 15203    Objective     =          -436.887676
Iteration: 15523    Objective     =          -449.584272
Elapsed time = 142.55 sec. (148015.56 ticks, 15610 iterations)
Iteration: 15914    Objective     =          -474.722527
Iteration: 16354    Objective     =          -495.308699
Iteration: 16681    Objective     =          -512.384292
Iteration: 17028    Objective     =          -532.553362
Iteration: 17415    Objective     =          -553.864216
Iteration: 17942    Objective     =          -591.072845
Iteration: 18283    Objective     =          -611.903525
Iteration: 18679    Objective     =          -638.974805
Elapsed time = 159.76 sec. (158016.55 ticks, 18942 iterations)
Iteration: 19107    Objective     =          -654.231370
Iteration: 19848    Objective     =          -695.346404
Iteration: 20276    Objective     =          -720.833138
Iteration: 20708    Objective     =          -739.081169
Iteration: 21060    Objective     =          -768.053862
Iteration: 21607    Objective     =          -798.233432
Iteration: 22101    Objective     =          -824.045004
Iteration: 22574    Objective     =          -853.558286
Elapsed time = 177.08 sec. (168016.92 ticks, 22891 iterations)
Iteration: 23104    Objective     =          -881.361257
Iteration: 23490    Objective     =          -903.056731
Iteration: 23944    Objective     =          -924.660112
Iteration: 24743    Objective     =          -964.340597
Iteration: 25132    Objective     =          -981.486886
Iteration: 25709    Objective     =          -999.310119
Iteration: 26495    Objective     =         -1038.874825
Iteration: 27004    Objective     =         -1061.019561
Iteration: 27861    Objective     =         -1103.315801
Elapsed time = 195.56 sec. (178020.78 ticks, 28181 iterations)
Iteration: 28258    Objective     =         -1115.987610
Iteration: 28813    Objective     =         -1148.103601
Iteration: 29180    Objective     =         -1173.943881
Iteration: 29995    Objective     =         -1203.407179
Iteration: 30389    Objective     =         -1226.213972
Iteration: 30949    Objective     =         -1245.106259
Iteration: 31774    Objective     =         -1269.404153
Iteration: 32292    Objective     =         -1331.592543
Elapsed time = 213.58 sec. (188021.51 ticks, 32587 iterations)
Iteration: 32674    Objective     =         -1355.556626
Iteration: 33252    Objective     =         -1392.568755
Iteration: 33713    Objective     =         -1433.855944
Iteration: 34509    Objective     =         -1497.358595
Iteration: 35178    Objective     =         -1521.610674
Iteration: 35827    Objective     =         -1529.875445
Iteration: 36555    Objective     =         -1532.167617
Iteration: 36925    Objective     =         -1545.403353
Elapsed time = 231.76 sec. (198022.39 ticks, 37174 iterations)
Iteration: 37494    Objective     =         -1551.742245
Iteration: 37983    Objective     =         -1560.512120
Iteration: 38669    Objective     =         -1567.190428
Iteration: 39342    Objective     =         -1573.687289
Iteration: 39974    Objective     =         -1580.265411
Iteration: 40804    Objective     =         -1585.557464
Iteration: 41441    Objective     =         -1594.114455
Elapsed time = 250.91 sec. (208022.86 ticks, 41603 iterations)
Iteration: 41866    Objective     =         -1605.409230
Iteration: 42463    Objective     =         -1611.633445
Iteration: 43179    Objective     =         -1613.744474
Iteration: 43772    Objective     =         -1619.172999
Iteration: 44329    Objective     =         -1630.115075
Iteration: 44894    Objective     =         -1633.388895
Iteration: 45471    Objective     =         -1637.254255
Elapsed time = 269.15 sec. (218024.86 ticks, 45816 iterations)
Iteration: 45977    Objective     =         -1639.963929
Iteration: 46566    Objective     =         -1641.669141
Iteration: 46985    Objective     =         -1642.953704
Iteration: 47408    Objective     =         -1644.865405
Iteration: 47778    Objective     =         -1647.128015
Iteration: 48255    Objective     =         -1648.397313
Iteration: 48636    Objective     =         -1649.957482
Iteration: 49136    Objective     =         -1650.574513
Elapsed time = 287.69 sec. (228028.45 ticks, 49159 iterations)
Iteration: 49466    Objective     =         -1652.025450
Iteration: 49864    Objective     =         -1653.564893
Iteration: 50250    Objective     =         -1654.266108
Iteration: 50702    Objective     =         -1654.595415
Iteration: 51189    Objective     =         -1655.122339
Iteration: 51732    Objective     =         -1655.273304
Iteration: 52193    Objective     =         -1661.496589
Iteration: 52610    Objective     =         -1663.527892
Elapsed time = 306.35 sec. (238030.88 ticks, 52765 iterations)
Iteration: 53086    Objective     =         -1663.745052
Removing shift (47139).
Iteration: 53284   Dual objective     =            -0.000000

This re-optimization takes some time.

Note that, although the column generation pricing sub-problems are NP-hard,
it happens frequently that 95% of the column generation time is spent in re-optimizing restricted master problems,
which is very unusual.

You're right, matrix coefficients on the order of 1e-9 will be removed.
But, we will still have real coefficients with many digits, while we don't change our model.

Originally posted by: ND10_Xavier_Schepler

After removing matrix coefficients on the order of 1e-9, I got the following 2 logs
produced by the same instance :
 

Tried aggregator 1 time.
LP Presolve eliminated 1182 rows and 1869 columns.
Reduced LP has 74173 rows, 247879 columns, and 1422191 nonzeros.
Presolve time = 0.34 sec. (230.25 ticks)
Initializing dual steep norms . . .

Iteration log . . .
Iteration:     1   Dual objective     =             0.000000
Perturbation started.
Iteration:   101   Dual objective     =             0.000000
Iteration:   739   Dual objective     =             0.005127
Iteration:  1801   Dual objective     =             0.022987
Iteration:  2231   Dual objective     =             0.028483
Iteration:  3035   Dual objective     =             0.036638
Iteration:  3964   Dual objective     =             0.045747
Iteration:  4307   Dual objective     =             0.048188
Iteration:  5204   Dual objective     =             0.057657
Iteration:  5508   Dual objective     =             0.060637
Iteration:  6351   Dual objective     =            10.564421
Iteration:  7210   Dual objective     =            10.572291
Iteration:  7474   Dual objective     =            10.574543
Iteration:  8223   Dual objective     =            10.580937
Iteration:  8983   Dual objective     =            10.587830
Iteration:  9377   Dual objective     =            10.589361
Iteration:  9760   Dual objective     =            10.591752
Iteration: 10116   Dual objective     =            10.594525
Iteration: 10523   Dual objective     =            10.597092
Iteration: 10934   Dual objective     =            10.602643
Iteration: 11310   Dual objective     =            10.605796
Iteration: 11687   Dual objective     =            10.610743
Iteration: 12034   Dual objective     =            10.611445
Removing perturbation.
Initializing dual steep norms . . .
 

After columns are added  :

Initializing primal norms rowwise . . .
Initializing primal norms rowwise . . .
Elapsed time = 66.71 sec. (88236.66 ticks, 1 iterations)

Iteration log . . .
Iteration:     1    Objective     =            10.500000
Iteration:   172    Objective     =            10.500000
Iteration:   394    Objective     =            10.463803
Iteration:   632    Objective     =            10.282968
Iteration:   894    Objective     =            10.069641
Iteration:  1137    Objective     =             8.883516
Iteration:  1391    Objective     =             6.264740
Iteration:  1656    Objective     =             4.656698
Iteration:  1900    Objective     =             4.459401
Elapsed time = 82.63 sec. (98240.74 ticks, 1981 iterations)
Iteration:  2132    Objective     =             4.210393
Iteration:  2407    Objective     =             3.622289
Iteration:  2707    Objective     =             1.585996
Iteration:  2947    Objective     =             1.301343
Iteration:  3197    Objective     =             0.950953
Iteration:  3461    Objective     =            -0.404605
Iteration:  3712    Objective     =            -0.920077
Elapsed time = 101.51 sec. (108244.65 ticks, 3989 iterations)
Iteration:  3989    Objective     =            -2.754957
Iteration:  4242    Objective     =            -3.872646
Iteration:  4489    Objective     =            -3.983235
Iteration:  4724    Objective     =            -5.074538
Iteration:  4952    Objective     =            -6.166436
Iteration:  5193    Objective     =            -8.181996
Iteration:  5444    Objective     =            -9.748623
Iteration:  5697    Objective     =           -15.196552
Elapsed time = 121.90 sec. (118248.09 ticks, 5877 iterations)
Iteration:  5944    Objective     =           -19.132192
Iteration:  6193    Objective     =           -25.038599
Iteration:  6441    Objective     =           -35.119647
Iteration:  6698    Objective     =           -50.981097
Iteration:  6988    Objective     =           -66.470842
Iteration:  7266    Objective     =           -83.784118
Iteration:  7572    Objective     =           -99.309542
Iteration:  7866    Objective     =          -113.029061
Elapsed time = 139.91 sec. (128248.17 ticks, 7919 iterations)
Iteration:  8175    Objective     =          -122.435020
Iteration:  8550    Objective     =          -163.282213
Iteration:  8840    Objective     =          -186.788267
Iteration:  9153    Objective     =          -207.122608
Iteration:  9456    Objective     =          -232.569338
Iteration:  9751    Objective     =          -246.389513
Iteration: 10093    Objective     =          -267.452660
Iteration: 10435    Objective     =          -288.968766
Elapsed time = 161.66 sec. (138250.15 ticks, 10463 iterations)
Iteration: 10879    Objective     =          -330.681499
Iteration: 11265    Objective     =          -357.966639
Iteration: 11643    Objective     =          -374.296727
Iteration: 12035    Objective     =          -391.272625
Iteration: 12371    Objective     =          -429.029540
Iteration: 12702    Objective     =          -446.668787
Iteration: 13153    Objective     =          -462.850536
Iteration: 13501    Objective     =          -479.183990
Elapsed time = 185.74 sec. (148250.64 ticks, 13600 iterations)
Iteration: 13871    Objective     =          -513.387452
Iteration: 14266    Objective     =          -543.465078
Iteration: 14606    Objective     =          -563.753661
Iteration: 15199    Objective     =          -599.838565
Iteration: 15587    Objective     =          -622.054691
Iteration: 15954    Objective     =          -665.648332
Iteration: 16411    Objective     =          -709.885655
Iteration: 16942    Objective     =          -760.168222
Elapsed time = 207.17 sec. (158254.94 ticks, 17152 iterations)
Iteration: 17268    Objective     =          -790.633329
Iteration: 17661    Objective     =          -815.128043
Iteration: 18078    Objective     =          -847.327337
Iteration: 18695    Objective     =          -892.775595
Iteration: 19128    Objective     =          -914.651444
Iteration: 19453    Objective     =          -936.634480
Iteration: 19874    Objective     =          -958.717502
Iteration: 20554    Objective     =         -1023.444618
Iteration: 20929    Objective     =         -1050.237614
Elapsed time = 226.46 sec. (168256.11 ticks, 21107 iterations)
Iteration: 21410    Objective     =         -1088.289820
Iteration: 21766    Objective     =         -1117.734267
Iteration: 22196    Objective     =         -1152.003607
Iteration: 22795    Objective     =         -1193.641622
Iteration: 23474    Objective     =         -1261.922007
Iteration: 24057    Objective     =         -1311.766490
Iteration: 24626    Objective     =         -1360.359533
Iteration: 25079    Objective     =         -1402.718826
Iteration: 25555    Objective     =         -1443.430023
Elapsed time = 246.01 sec. (178257.69 ticks, 26077 iterations)
Iteration: 26191    Objective     =         -1475.920063
Iteration: 26807    Objective     =         -1531.481854
Iteration: 27178    Objective     =         -1560.725595
Iteration: 27869    Objective     =         -1617.606983
Iteration: 28456    Objective     =         -1684.186508
Iteration: 28924    Objective     =         -1700.968319
Iteration: 29434    Objective     =         -1726.858654
Iteration: 29949    Objective     =         -1756.673146
Iteration: 30455    Objective     =         -1788.685861
Elapsed time = 267.44 sec. (188260.18 ticks, 30540 iterations)
Iteration: 30918    Objective     =         -1810.273173
Iteration: 31394    Objective     =         -1831.055969
Iteration: 31992    Objective     =         -1873.628785
Iteration: 32473    Objective     =         -1900.219408
Iteration: 32935    Objective     =         -1923.042201
Iteration: 33408    Objective     =         -1965.606545
Iteration: 34030    Objective     =         -1997.514911
Iteration: 34713    Objective     =         -2014.680224
Elapsed time = 287.13 sec. (198261.14 ticks, 35075 iterations)
Iteration: 35306    Objective     =         -2034.796562
Iteration: 35912    Objective     =         -2057.559964
Iteration: 36676    Objective     =         -2118.286456
Iteration: 37058    Objective     =         -2136.110066
Iteration: 37572    Objective     =         -2158.395790
Iteration: 38543    Objective     =         -2220.562806
Iteration: 39066    Objective     =         -2248.581169
Iteration: 39752    Objective     =         -2305.230199
Elapsed time = 305.86 sec. (208263.60 ticks, 40382 iterations)
Iteration: 40508    Objective     =         -2347.319287
Iteration: 41337    Objective     =         -2440.701686
Iteration: 41901    Objective     =         -2490.948635
Iteration: 42655    Objective     =         -2495.827080
Iteration: 43326    Objective     =         -2533.530334
Iteration: 44119    Objective     =         -2536.639912
Iteration: 44734    Objective     =         -2593.290602
Iteration: 45315    Objective     =         -2605.991185
Elapsed time = 323.10 sec. (218263.88 ticks, 45390 iterations)
Iteration: 45796    Objective     =         -2622.203089
Iteration: 46543    Objective     =         -2627.055495
Iteration: 47489    Objective     =         -2645.687735
Iteration: 48007    Objective     =         -2663.377277
Iteration: 48626    Objective     =         -2674.198890
Iteration: 49070    Objective     =         -2686.659845
Elapsed time = 342.78 sec. (228267.13 ticks, 49267 iterations)
Iteration: 49550    Objective     =         -2698.856637
Iteration: 50263    Objective     =         -2703.413956
Iteration: 50817    Objective     =         -2710.207650
Iteration: 51458    Objective     =         -2718.922237
Iteration: 52105    Objective     =         -2723.810755
Iteration: 52674    Objective     =         -2730.096356
Elapsed time = 361.06 sec. (238267.59 ticks, 53157 iterations)
Iteration: 53356    Objective     =         -2736.713167
Iteration: 53825    Objective     =         -2741.354265
Iteration: 54281    Objective     =         -2743.765101
Iteration: 54780    Objective     =         -2746.174909
Iteration: 55210    Objective     =         -2747.411924
Iteration: 55681    Objective     =         -2748.788566
Iteration: 56052    Objective     =         -2750.263003
Elapsed time = 379.31 sec. (248268.62 ticks, 56441 iterations)
Iteration: 56522    Objective     =         -2751.059613
Iteration: 56983    Objective     =         -2751.904304
Iteration: 57472    Objective     =         -2752.272282
Iteration: 57895    Objective     =         -2758.374143
Iteration: 58295    Objective     =         -2762.773575
Removing shift (58265).
Iteration: 58331   Dual objective     =             0.000000

It doesn't seem to help.

Originally posted by: EdKlotz

Yes, I zeroed them out using the "change value" command in interactive CPLEX, and I didn't see any significant improvement.

I see from the log file above that you indeed do use primal simplex after adding the columns.   Does the log from above involve the addition of just one column?   If not, how many?

Originally posted by: ND10_Xavier_Schepler

There are a little less than twenty columns added.

Originally posted by: EdKlotz

If those 20 columns you add enable a massive improvement in the objective function, then a long sequence of iterations is possible.  Looking at the iteration log from above, that is indeed the case.   The change in objective between iteration 0 and the last iteration of the reoptimized problem dramatically exceeds the change in the first optimization done with dual simplex.    More generally, if your restricted master currently has a collection of "bad" columns relative to the final optimal basis of the whole problem, and your subproblem generates numerous good columns, the optimal basis from the restricted master may not be particularly helpful.  If you set the advanced start indicator to 0 to instruct CPLEX to start from scratch, does the run time for the second optimization improve or get worse?   CPLEX also supports a setting of 2 for the advanced start indicator, which translates the optimal solution (not the optimal basis) from the
 previously optimized problem into a starting solution for the presolved model after modifications, then constructs a starting basis
 for the presolved model from that solution.   This basis may not be as accurate as one provided for the original problem, but you do
 benefit from the presolve reductions.    I'm not sure this will help in your case, as the log above indicates only a moderate number of iterations.   But, it's worth a try.

Finally, turning on CPLEX's presolve dual parameter and running dual simplex improves performance significantly on the model you uploaded.   Unfortunately, this feature doesn't support restarts.    But, this does raise the question of whether your decomposition algorithm would run faster if you optimized the dual of your current restricted master, then used your subproblem to generate rows, then reoptimized with the dual simplex method.