Decision Optimization

Decision Optimization

Delivers prescriptive analytics capabilities and decision intelligence to improve decision-making.


#Analytics
#DecisionOptimization
#DecisionOptimization
 View Only
  • 1.  cplex stops as optimal without reaching terminating optimality gap tolerance

    Posted 03/26/14 11:41 PM

    Originally posted by: pankaichn


    I use cplex 12.5 with C++ concert technology to solve a mixed-integer linear program problem. All the cplex are default. It stops with a solution that is shown optimal, but it doesn't reach the default relative mip gap tolerance, which is 0.01%. It seems weird to me. Is it possible for cplex to stop and show the solution is optimal, without reaching terminating optimality gap tolerance?

     

    The output details are attached as follows.

     

    Found incumbent of value 0.000000 after -0.00 sec. (0.70 ticks)
    Tried aggregator 1 time.
    MIP Presolve eliminated 13650 rows and 1 columns.
    Reduced MIP has 12231 rows, 16380 columns, and 46247 nonzeros.
    Reduced MIP has 4095 binaries, 0 generals, 0 SOSs, and 0 indicators.
    Presolve time = 0.11 sec. (48.00 ticks)
    Probing time = 0.01 sec. (2.68 ticks)
    Tried aggregator 1 time.
    Presolve time = 0.08 sec. (20.80 ticks)
    Probing time = 0.03 sec. (2.68 ticks)
    Clique table members: 1.
    MIP emphasis: balance optimality and feasibility.
    MIP search method: dynamic search.
    Parallel mode: deterministic, using up to 4 threads.
    Parallel mode: deterministic, using up to 2 threads for concurrent optimization.
    Tried aggregator 1 time.
    LP Presolve eliminated 1 rows and 2 columns.
    Reduced LP has 12230 rows, 16378 columns, and 46244 nonzeros.
    Presolve time = 0.03 sec. (10.23 ticks)
    Initializing dual steep norms . . .
     
    Iteration log . . .
    Iteration:     1   Dual objective     =         23903.899240
    Iteration:   426   Dual objective     =         13248.206306
    Iteration:   802   Dual objective     =          8855.015347
    Iteration:  1312   Dual objective     =          5273.295616
    Iteration:  1555   Dual objective     =          4870.932080
    Iteration:  1868   Dual objective     =          4685.436668
    Iteration:  2131   Dual objective     =          4549.945815
    Iteration:  2416   Dual objective     =          4147.997603
    Iteration:  2773   Dual objective     =          4008.245943
    Iteration:  3100   Dual objective     =          3811.128809
    Iteration:  3486   Dual objective     =          3765.238329
    Iteration:  3759   Dual objective     =          3743.783509
    Iteration:  4066   Dual objective     =          3726.025371
    Iteration:  4325   Dual objective     =          3716.392166
    Reinitializing dual norms . . .
    Initializing dual steep norms . . .
     
    Dual simplex solved model.
     
    Root relaxation solution time = 0.86 sec. (256.04 ticks)
     
            Nodes                                         Cuts/
       Node  Left     Objective  IInf  Best Integer    Best Bound    ItCnt     Gap
     
    *     0+    0                            0.0000    25268.7175     4336     --- 
    Found incumbent of value 0.000000 after 1.42 sec. (351.22 ticks)
    *     0+    0                         1563.3195    25268.7175     4336     --- 
    Found incumbent of value 1563.319510 after 1.42 sec. (351.53 ticks)
          0     0     3716.3823  1988     1563.3195     3716.3823     4336  137.72%
    *     0+    0                         3181.3941     3716.3823     4336   16.82%
    Found incumbent of value 3181.394101 after 1.61 sec. (451.63 ticks)
          0     0     3443.1699  1848     3181.3941    Cuts: 3157     7731    8.23%
          0     0     3376.5451  1896     3181.3941    Cuts: 2026     9455    6.13%
    *     0+    0                         3185.1099     3376.5451     9455    6.01%
    Found incumbent of value 3185.109884 after 4.93 sec. (2091.61 ticks)
          0     0     3354.6430  1834     3185.1099    Cuts: 1376    10377    5.32%
    *     0+    0                         3189.6065     3354.6430    10989    5.17%
    Found incumbent of value 3189.606459 after 6.37 sec. (2706.52 ticks)
          0     0     3344.5103  1767     3189.6065     Cuts: 915    10989    4.86%
          0     0     3339.8456  1751     3189.6065     Cuts: 766    11460    4.71%
    *     0+    0                         3191.0026     3339.8456    11460    4.66%
    Found incumbent of value 3191.002564 after 7.35 sec. (3117.64 ticks)
          0     0     3336.8527  1792     3191.0026     Cuts: 617    11828    4.57%
          0     0     3333.1143  1756     3191.0026     Cuts: 504    12154    4.45%
          0     0     3332.3010  1772     3191.0026     Cuts: 367    12393    4.43%
          0     0     3332.0602  1759     3191.0026     Cuts: 256    12516    4.42%
          0     0     3331.6563  1755     3191.0026     Cuts: 126    12620    4.41%
          0     0     3330.8418  1747     3191.0026     Cuts: 178    12721    4.38%
          0     0     3330.5853  1756     3191.0026     Cuts: 127    12815    4.37%
    *     0+    0                         3203.4365     3330.5853    12880    3.97%
    Found incumbent of value 3203.436478 after 10.36 sec. (4412.67 ticks)
          0     0     3330.2602  1761     3203.4365      Cuts: 78    12880    3.96%
          0     2     3330.2602  1761     3203.4365     3330.2602    12880    3.96%
    Elapsed time = 12.40 sec. (5361.08 ticks, tree = 0.01 MB, solutions = 7)
         13     5     3254.6569   483     3203.4365     3257.5294    15153    1.69%
    *    17+    7                         3218.1579     3254.6412    15574    1.13%
                                                     Impl Bds: 29                  
    Found incumbent of value 3218.157949 after 13.18 sec. (5782.51 ticks)
    *    26+   14                         3218.3100     3254.6412    15748    1.13%
                                                     Impl Bds: 14                  
    Found incumbent of value 3218.310001 after 13.70 sec. (6020.60 ticks)
         26    16     3247.8885   373     3218.3100     3254.6412    15748    1.13%
        147   117     3233.1312   295     3218.3100     3246.6547    18462    0.88%
                                                         Cuts: 26                  
        265   217     3238.5337   319     3218.3100     3243.8760    20529    0.79%
                                                          Cuts: 3                  
        379   313        cutoff           3218.3100     3243.8760    22530    0.79%
    *   391+  319                         3218.3122     3243.5697    22659    0.78%
    Found incumbent of value 3218.312222 after 16.71 sec. (6915.42 ticks)
        489   404     3222.6859   197     3218.3122     3243.5697    24578    0.78%
        639   532     3227.6035   237     3218.3122     3242.5463    26859    0.75%
        856   724     3219.3411   104     3218.3122     3241.3901    29332    0.72%
        997   842     3228.0744   265     3218.3122     3240.7575    31048    0.70%
    *  1246+  705                         3218.3282     3228.3713    40638    0.31%
    Found incumbent of value 3218.328246 after 24.37 sec. (9217.64 ticks)
     
    Implied bound cuts applied:  1769
    Flow cuts applied:  304
    Mixed integer rounding cuts applied:  1216
    Zero-half cuts applied:  186
    Gomory fractional cuts applied:  94
     
    Root node processing (before b&c):
      Real time             =   12.00 sec. (5268.81 ticks)
    Parallel b&c, 4 threads:
      Real time             =   27.75 sec. (9855.83 ticks)
      Sync time (average)   =    0.00 sec.
      Wait time (average)   =    0.00 sec.
                              ------------
    Total (root+branch&cut) =   39.75 sec. (15124.64 ticks)
    Solution Status
    Optimal

     

     

    You can see that cplex stop when only reaching a gap 0.31%.


    #CPLEXOptimizers
    #DecisionOptimization


  • 2.  Re: cplex stops as optimal without reaching terminating optimality gap tolerance

    Posted 03/27/14 02:36 AM

    You are misinterpreting the log here. CPLEX does not stop at gap 0.31%. This is only the last node log line it prints. By default, CPLEX does not print a log line for each node it processes. After printing the line with gap 0.31% it processes some more nodes but does not produce any log output for them. It manages to prove optimality before it would print the next node log line. That is why you do not see any additional node log lines. You can set the MIPInterval parameter to 1 to see a node log line for each node CPLEX processes. You could also query the number of nodes processed in your C++ application (IloCplex::getNnodes()) and you will see that this returns a value larger than 1246 (which is the last node for which CPLEX did print a log line).


    #CPLEXOptimizers
    #DecisionOptimization


  • 3.  Re: cplex stops as optimal without reaching terminating optimality gap tolerance

    Posted 03/27/14 10:56 AM

    Originally posted by: pankaichn


    Hi Daniel,

    You are exactly right. Now I obtain the node log information for every node after setting MIPInterval to 1. Thanks a lot!


    #CPLEXOptimizers
    #DecisionOptimization


  • 4.  Re: cplex stops as optimal without reaching terminating optimality gap tolerance

    Posted 03/27/14 11:22 AM

    Originally posted by: pankaichn


    Problem still unsolved....I run another instance of my problem after setting MIPInterval parameter to 1. Although Cplex output the node log information for every node before it stops, but it still stops with a gap large than the default relative terminating gap tolerance 0.01%. Do I miss anything else?

     

    Found incumbent of value 0.000000 after 0.00 sec. (0.70 ticks)
    Tried aggregator 1 time.
    MIP Presolve eliminated 13650 rows and 1 columns.
    Reduced MIP has 12231 rows, 16380 columns, and 46247 nonzeros.
    Reduced MIP has 4095 binaries, 0 generals, 0 SOSs, and 0 indicators.
    Presolve time = 0.09 sec. (48.00 ticks)
    Probing time = 0.02 sec. (2.68 ticks)
    Tried aggregator 1 time.
    Presolve time = 0.06 sec. (20.80 ticks)
    Probing time = 0.02 sec. (2.68 ticks)
    Clique table members: 1.
    MIP emphasis: balance optimality and feasibility.
    MIP search method: dynamic search.
    Parallel mode: deterministic, using up to 4 threads.
    Parallel mode: deterministic, using up to 2 threads for concurrent optimization.
    Tried aggregator 1 time.
    LP Presolve eliminated 1 rows and 2 columns.
    Reduced LP has 12230 rows, 16378 columns, and 46244 nonzeros.
    Presolve time = 0.05 sec. (10.23 ticks)
    Initializing dual steep norms . . .
     
    Iteration log . . .
    Iteration:     1   Dual objective     =         22689.013259
    Iteration:   418   Dual objective     =         12640.514456
    Iteration:   809   Dual objective     =          9515.030194
    Iteration:  1284   Dual objective     =          5149.843065
    Iteration:  1576   Dual objective     =          4719.754138
    Iteration:  1879   Dual objective     =          4545.142295
    Iteration:  2128   Dual objective     =          4384.332018
    Iteration:  2420   Dual objective     =          3971.446977
    Iteration:  2763   Dual objective     =          3822.199298
    Iteration:  3109   Dual objective     =          3707.202376
    Iteration:  3501   Dual objective     =          3601.113826
    Iteration:  3783   Dual objective     =          3554.482756
    Iteration:  4053   Dual objective     =          3536.551463
    Iteration:  4327   Dual objective     =          3524.646309
    Reinitializing dual norms . . .
    Initializing dual steep norms . . .
     
    Dual simplex solved model.
     
    Root relaxation solution time = 0.58 sec. (212.95 ticks)
     
            Nodes                                         Cuts/
       Node  Left     Objective  IInf  Best Integer    Best Bound    ItCnt     Gap
     
    *     0+    0                            0.0000    25008.2979     4498     --- 
    Found incumbent of value 0.000000 after 1.03 sec. (308.13 ticks)
    *     0+    0                         1452.1693    25008.2979     4498     --- 
    Found incumbent of value 1452.169260 after 1.03 sec. (308.44 ticks)
          0     0     3521.9735  2052     1452.1693     3521.9735     4498  142.53%
    *     0+    0                         2925.7177     3521.9735     8020   20.38%
    Found incumbent of value 2925.717702 after 2.51 sec. (1100.56 ticks)
          0     0     3257.7566  1768     2925.7177    Cuts: 3157     8020   11.35%
    *     0+    0                         2932.0762     3257.7566     9765   11.11%
    Found incumbent of value 2932.076241 after 3.67 sec. (1657.80 ticks)
          0     0     3183.0420  1794     2932.0762    Cuts: 2493     9765    8.56%
    *     0+    0                         2937.8891     3183.0420    10703    8.34%
    Found incumbent of value 2937.889118 after 4.76 sec. (2152.64 ticks)
          0     0     3160.3833  1810     2937.8891    Cuts: 1598    10703    7.57%
          0     0     3147.7320  1806     2937.8891    Cuts: 1227    11477    7.14%
          0     0     3138.5589  1802     2937.8891    Cuts: 1220    12147    6.83%
          0     0     3131.7807  1831     2937.8891    Cuts: 1067    12652    6.60%
          0     0     3127.1875  1910     2937.8891     Cuts: 831    13170    6.44%
    *     0+    0                         2950.5075     3127.1875    13590    5.99%
    Found incumbent of value 2950.507473 after 8.83 sec. (4055.73 ticks)
          0     0     3124.4349  1828     2950.5075     Cuts: 722    13590    5.89%
          0     0     3121.8646  1814     2950.5075     Cuts: 636    13915    5.81%
          0     0     3119.4681  1810     2950.5075     Cuts: 511    14254    4.80%
          0     0     3118.5662  1833     2950.5075     Cuts: 359    14464    4.80%
    *     0+    0                         2950.8132     3092.0820    14464    4.79%
    Found incumbent of value 2950.813151 after 12.84 sec. (5929.57 ticks)
          0     2     3118.5662  1833     2950.8132     3072.3362    14464    4.12%
    Elapsed time = 12.95 sec. (5950.44 ticks, tree = 0.01 MB, solutions = 7)
          1     1        cutoff           2950.8132     3072.3362    14560    4.12%
          2     2     3097.0704  1701     2950.8132     3072.3362    15364    4.12%
          3     1        cutoff           2950.8132     3072.3362    15382    4.12%
          4     2     3096.0935  1456     2950.8132     3072.3362    15437    4.12%
          5     3     3081.5569  1309     2950.8132     3072.3362    15690    4.12%
          6     4     3056.3125  1164     2950.8132     3072.3362    16046    4.12%
          7     5     3005.6350  1163     2950.8132     3072.3362    16483    4.12%
          8     6     2980.3903  1017     2950.8132     3072.3362    17001    4.12%
          9     7     2979.0247   998     2950.8132     3072.3362    17100    4.12%
         10     6        cutoff           2950.8132     3072.3362    17102    4.12%
    Elapsed time = 13.48 sec. (6200.95 ticks, tree = 0.01 MB, solutions = 7)
         11     5        cutoff           2950.8132     3072.3362    17156    4.12%
         12     6     3020.0911   978     2950.8132     3072.3362    17358    4.12%
         13     5        cutoff           2950.8132     3072.3362    17404    4.12%
         14     6     2951.5013   948     2950.8132     3072.3362    17574    4.12%
         15     5        cutoff           2950.8132     3072.3362    17969    4.12%
         16     6     3013.6925   888     2950.8132     3020.0702    18067    2.35%
         17     7     2972.6261   908     2950.8132     3020.0702    18170    2.35%
         18     6        cutoff           2950.8132     3020.0702    18206    2.35%
         19     7     2966.8219   865     2950.8132     3020.0702    18455    2.35%
         20     8     3004.7813   825     2950.8132     3013.6796    18890    2.13%
                                                    Impl Bds: 107                  
    Elapsed time = 13.98 sec. (6515.49 ticks, tree = 0.02 MB, solutions = 7)
         21     9     2954.7865   620     2950.8132     3013.6796    19384    2.13%
         22     8        cutoff           2950.8132     3013.6796    19404    2.13%
         23     7        cutoff           2950.8132     3013.6796    19424    2.13%
         24     8     2997.8354   600     2950.8132     3013.6796    19653    2.13%
         25     7        cutoff           2950.8132     3013.6796    19680    2.13%
         26     6        cutoff           2950.8132     3013.6796    19682    2.13%
         27     5        cutoff           2950.8132     3013.6796    19805    2.13%
         28     6     2990.8935   511     2950.8132     3013.6390    19869    2.13%
         29     5        cutoff           2950.8132     3013.6390    20081    2.13%
         30     4        cutoff           2950.8132     3013.6390    20083    2.13%
    Elapsed time = 14.12 sec. (6565.61 ticks, tree = 0.01 MB, solutions = 7)
         31     3        cutoff           2950.8132     3013.6390    20099    2.13%
         32     4     2985.2284   554     2950.8132     3013.6390    20224    2.13%
         33     5     2973.1480   489     2950.8132     3013.6390    20237    2.13%
         34     6     2972.6284   419     2950.8132     3013.6390    20258    2.13%
         35     7     2965.3475   389     2950.8132     3013.6390    20319    2.13%
         36     8     2957.6890   445     2950.8132     3013.6390    20416    2.13%
         37     9     2963.4447   367     2950.8132     3013.6390    20442    2.13%
         38    10     2960.8057   453     2950.8132     2997.6522    20619    1.59%
         39     9        cutoff           2950.8132     2997.6522    20670    1.59%
         40    10     2984.7089   484     2950.8132     2997.6522    20691    1.59%
    Elapsed time = 14.26 sec. (6638.53 ticks, tree = 0.02 MB, solutions = 7)
         41     9        cutoff           2950.8132     2997.6522    20713    1.59%
         42    10     2963.3093   351     2950.8132     2997.6522    20722    1.59%
         43    11     2963.1640   395     2950.8132     2997.6522    20795    1.59%
         44    12     2982.0698   570     2950.8132     2997.6522    20947    1.59%
         45    11        cutoff           2950.8132     2997.6522    20950    1.59%
         46    12     2957.8317   397     2950.8132     2997.6522    21058    1.59%
         47    13     2960.5250   481     2950.8132     2997.6522    21265    1.59%
         48    14     2976.5875   614     2950.8132     2997.6522    21389    1.59%
         49    15     2963.1284   331     2950.8132     2997.6522    21405    1.59%
         50    16     2955.0475   527     2950.8132     2997.6522    21487    1.59%
    Elapsed time = 14.37 sec. (6678.82 ticks, tree = 0.01 MB, solutions = 7)
         51    17     2975.8724   548     2950.8132     2997.6522    21548    1.59%
         52    18     2961.9151   390     2950.8132     2997.6522    21623    1.59%
         53    17        cutoff           2950.8132     2997.6522    21703    1.59%
         54    18     2960.9923   366     2950.8132     2984.7043    21738    1.15%
                                                     Impl Bds: 22                  
         55    19     2954.2654   460     2950.8132     2984.7043    21810    1.15%
         56    20     2974.6039   606     2950.8132     2984.7043    21915    1.15%
         57    19        cutoff           2950.8132     2984.7043    21993    1.15%
         58    20     2960.7749   285     2950.8132     2984.7043    22028    1.15%
         59    21     2953.3537   437     2950.8132     2984.7043    22057    1.15%
         60    22     2974.3870   525     2950.8132     2984.7043    22088    1.15%
    Elapsed time = 14.46 sec. (6700.93 ticks, tree = 0.04 MB, solutions = 7)
         61    23     2955.2874   498     2950.8132     2984.7043    22230    1.15%
         62    24     2957.7966   263     2950.8132     2984.7043    22270    1.15%
         63    25     2952.3675   497     2950.8132     2984.7043    22348    1.15%
         64    26     2973.4353   437     2950.8132     2984.7043    22401    1.15%
         65    27     2954.3757   475     2950.8132     2984.7043    22425    1.15%
         66    28     2957.1910   240     2950.8132     2984.7043    22448    1.15%
         67    27        cutoff           2950.8132     2984.7043    22470    1.15%
         68    28     2970.4570   415     2950.8132     2984.7043    22516    1.15%
         69    29     2953.3896   535     2950.8132     2984.7043    22589    1.15%
         70    30     2956.7566   232     2950.8132     2984.7043    22605    1.15%
     

    //let's miss the lengthy output in the middle part...

     

    Elapsed time = 30.16 sec. (11025.45 ticks, tree = 67.45 MB, solutions = 13)
       2361  1451     2957.6176   149     2953.2090     2962.3810    60479    0.31%
       2362  1452     2956.5583   161     2953.2090     2962.3810    60485    0.31%
       2363  1451        cutoff           2953.2090     2962.3810    60486    0.31%
       2364  1452     2958.8796   136     2953.2090     2962.3810    60501    0.31%
       2365  1453     2956.8199   142     2953.2090     2962.3810    60519    0.31%
       2366  1454     2955.7606   154     2953.2090     2962.3810    60562    0.31%
       2367  1455     2956.6171   173     2953.2090     2962.3810    60578    0.31%
       2368  1456     2958.5001   130     2953.2090     2962.3810    60591    0.31%
       2369  1457     2956.1896   136     2953.2090     2962.3810    60606    0.31%
       2370  1458     2955.1303   148     2953.2090     2962.3810    60618    0.31%
    Elapsed time = 30.20 sec. (11047.02 ticks, tree = 67.47 MB, solutions = 13)
       2371  1459     2955.5662   167     2953.2090     2962.3810    60630    0.31%
       2372  1460     2957.6647   124     2953.2090     2962.3810    60642    0.31%
       2373  1461     2955.8102   130     2953.2090     2962.3810    60651    0.31%
       2374  1462     2954.4429   142     2953.2090     2962.3810    60661    0.31%
       2375  1463     2954.9244   221     2953.2090     2962.3810    60713    0.31%
       2376  1464     2956.9725   118     2953.2090     2962.3810    60718    0.31%
       2377  1465     2955.1228   124     2953.2090     2962.3810    60728    0.31%
       2378  1466     2953.7507   136     2953.2090     2962.3810    60733    0.31%
       2379  1465        cutoff           2953.2090     2962.3810    60743    0.31%
       2380  1466     2956.2251   112     2953.2090     2962.3810    60755    0.31%
    Elapsed time = 30.22 sec. (11056.69 ticks, tree = 67.48 MB, solutions = 13)
       2381  1467     2954.4306   118     2953.2090     2962.3810    60760    0.31%
       2382  1468     2956.0370   106     2953.2090     2962.3810    60774    0.31%
       2383  1469     2953.3910   112     2953.2090     2962.3810    60782    0.31%
       2384  1470     2955.9079   100     2953.2090     2962.3810    60791    0.31%
       2385  1469        cutoff           2953.2090     2962.3810    60802    0.31%
       2386  1470     2955.0611    94     2953.2090     2962.3810    60814    0.31%
       2387  1469        cutoff           2953.2090     2962.3810    60816    0.31%
       2388  1470     2954.4870    88     2953.2090     2962.3810    60826    0.31%
       2389  1471     2960.3309   149     2953.2090     2962.3810    60836    0.31%
       2390  1472     2954.3817    82     2953.2090     2962.3810    60841    0.31%
    Elapsed time = 30.22 sec. (11056.69 ticks, tree = 69.00 MB, solutions = 13)
       2391  1473     2960.2931   143     2953.2090     2962.3810    60844    0.31%
       2392  1473     2953.5463    78     2953.2090     2962.3810    60861    0.31%
       2393  1474     2959.4954   136     2953.2090     2962.3810    60878    0.31%
       2394  1473        cutoff           2953.2090     2962.3810    60884    0.31%
       2395  1474     2958.8652   130     2953.2090     2962.3810    60899    0.31%
       2396  1475     2960.7045   167     2953.2090     2962.3810    60915    0.31%
       2397  1476     2957.8646   124     2953.2090     2962.3810    60923    0.31%
       2398  1477     2959.6537   161     2953.2090     2962.3810    60935    0.31%
       2399  1478     2957.1724   118     2953.2090     2962.3810    60940    0.31%
       2400  1479     2959.0308   218     2953.2090     2962.3810    60993    0.31%
    Elapsed time = 30.22 sec. (11056.69 ticks, tree = 69.00 MB, solutions = 13)
       2401  1480     2956.4251   112     2953.2090     2962.3810    61005    0.31%
       2402  1481     2959.0067   155     2953.2090     2962.3810    61014    0.31%
       2403  1482     2956.2369   106     2953.2090     2962.3810    61022    0.31%
       2404  1483     2957.2854   149     2953.2090     2962.3810    61034    0.31%
       2405  1484     2956.1078   100     2953.2090     2962.3810    61043    0.31%
       2406  1485     2957.1697   143     2953.2090     2962.3810    61051    0.31%
       2407  1486     2955.2611    94     2953.2090     2962.3810    61063    0.31%
       2408  1487     2956.3720   136     2953.2090     2962.3810    61092    0.31%
       2409  1488     2954.6870    88     2953.2090     2962.3810    61102    0.31%
       2410  1489     2955.7418   130     2953.2090     2962.3810    61115    0.31%
    Elapsed time = 30.22 sec. (11056.69 ticks, tree = 69.00 MB, solutions = 13)
       2411  1490     2954.5817    82     2953.2090     2962.3810    61120    0.31%
       2412  1491     2954.7412   124     2953.2090     2962.3810    61131    0.31%
       2413  1492     2954.0490   118     2953.2090     2962.3810    61137    0.31%
       2414  1491        cutoff           2953.2090     2962.3810    61141    0.31%
       2415  1492     2953.3713   130     2953.2090     2962.2708    61149    0.31%
       2416  1491        cutoff           2953.2090     2962.2708    61157    0.31%
       2417  1490     2953.3016   112     2953.2090     2962.2708    61169    0.31%
       2418  1491     2953.7463    78     2953.2090     2962.2708    61186    0.31%
       2419  1490        cutoff           2953.2090     2962.2708    61191    0.31%
       2420  1491     2961.2397   181     2953.2090     2962.2708    61209    0.31%
    Elapsed time = 30.64 sec. (11147.56 ticks, tree = 67.99 MB, solutions = 13)
       2421  1492     2959.5459   161     2953.2090     2962.2708    61239    0.31%
       2422  1493     2953.3939    72     2953.2090     2962.2708    61246    0.31%
       2423  1492        cutoff           2953.2090     2962.2708    61247    0.31%
       2424  1493     2960.1888   175     2953.2090     2962.2708    61264    0.31%
       2425  1494     2958.8236   155     2953.2090     2962.2708    61282    0.31%
       2426  1493        cutoff           2953.2090     2962.2708    61282    0.31%
       2427  1494     2958.6770   185     2953.2090     2962.2708    61326    0.31%
       2428  1495     2959.5637   231     2953.2090     2962.2708    61412    0.31%
       2429  1496     2957.7728   149     2953.2090     2962.2708    61429    0.31%
       2430  1495        cutoff           2953.2090     2962.2708    61430    0.31%
    Elapsed time = 30.73 sec. (11208.72 ticks, tree = 68.00 MB, solutions = 13)
       2431  1496     2957.6262   179     2953.2090     2962.2708    61442    0.31%
       2432  1497     2959.5419   169     2953.2090     2962.2708    61451    0.31%
       2433  1498     2956.0515   143     2953.2090     2962.2708    61464    0.31%
       2434  1499     2960.2750   143     2953.2090     2962.2708    61472    0.31%
       2435  1500     2955.9049   173     2953.2090     2962.2708    61484    0.31%
       2436  1501     2957.8205   163     2953.2090     2962.2708    61495    0.31%
       2437  1502     2955.2538   136     2953.2090     2962.2708    61520    0.31%
       2438  1503     2959.2242   137     2953.2090     2962.2708    61532    0.31%
       2439  1504     2955.8439   167     2953.2090     2962.2708    61542    0.31%
       2440  1505     2957.7596   157     2953.2090     2962.2708    61550    0.31%
    Elapsed time = 30.75 sec. (11218.36 ticks, tree = 68.01 MB, solutions = 13)
       2441  1506     2954.6236   130     2953.2090     2962.2708    61564    0.31%
       2442  1507     2958.4265   130     2953.2090     2962.2708    61585    0.31%
       2443  1508     2955.8062   161     2953.2090     2962.2708    61588    0.31%
       2444  1509     2957.7218   151     2953.2090     2962.2708    61591    0.31%
       2445  1510     2953.6230   124     2953.2090     2962.2708    61596    0.31%
       2446  1511     2957.7963   124     2953.2090     2962.2708    61608    0.31%
       2447  1512     2955.6905   155     2953.2090     2962.2708    61616    0.31%
       2448  1513     2957.6329   145     2953.2090     2962.2708    61625    0.31%
       2449  1512        cutoff           2953.2090     2962.2708    61626    0.31%
       2450  1513     2956.7957   118     2953.2090     2962.2708    61637    0.31%
    Elapsed time = 30.76 sec. (11231.40 ticks, tree = 68.03 MB, solutions = 13)
       2451  1514     2955.6016   149     2953.2090     2962.2708    61643    0.31%
       2452  1515     2956.8352   138     2953.2090     2962.2708    61699    0.31%
       2453  1514        cutoff           2953.2090     2962.2708    61700    0.31%
       2454  1515     2956.1035   112     2953.2090     2962.2708    61706    0.31%
    *  2455+ 1009                         2953.2571     2962.1369    69522    0.30%
    Found incumbent of value 2953.257146 after 34.68 sec. (12594.29 ticks)
    *  2455+  672                         2953.2686     2962.1369    69522    0.30%
    Found incumbent of value 2953.268609 after 35.30 sec. (12745.92 ticks)
    *  2455+  448                         2953.4510     2962.1369    71136    0.29%
    Found incumbent of value 2953.451010 after 40.89 sec. (14995.15 ticks)
    *  2455+  298                         2953.6000     2961.2781    76086    0.26%
    Found incumbent of value 2953.600019 after 47.22 sec. (18120.12 ticks)
     
    Implied bound cuts applied:  1286
    Flow cuts applied:  171
    Mixed integer rounding cuts applied:  1499
    Zero-half cuts applied:  186
    Gomory fractional cuts applied:  54
     
    Root node processing (before b&c):
      Real time             =   12.61 sec. (5858.01 ticks)
    Parallel b&c, 4 threads:
      Real time             =   37.24 sec. (13609.60 ticks)
      Sync time (average)   =    0.00 sec.
      Wait time (average)   =    0.00 sec.
                              ------------
    Total (root+branch&cut) =   49.84 sec. (19467.61 ticks)
    Solution Status
    Optimal
    Final No of Nodes
    2455
    Final No of Nodes Left
    299

     

    You see, it output every node information before the 2455th node, but it stops at the node 2455 with gap 0.26%. I also query the number of nodes and nodes left using (IloCplex::getNnodes()), which are shown in the last four lines.


    #CPLEXOptimizers
    #DecisionOptimization


  • 5.  Re: cplex stops as optimal without reaching terminating optimality gap tolerance

    Posted 03/28/14 01:50 AM

    That indeed looks odd. What do cplex.getObjValue(), cplex.getBestObjValue() and cplex.getMIPRelativeGap() return after cplex.solve() returns?

    Do you have any non-default parameter settings?

    Could you export your model as a SAV file (cplex.exportModel("model.sav")) and share it here?


    #CPLEXOptimizers
    #DecisionOptimization


  • 6.  Re: cplex stops as optimal without reaching terminating optimality gap tolerance

    Posted 03/28/14 02:34 PM

    Originally posted by: pankaichn


    I've set the following parameters: setParam(IloCplex::TiLim, 3600); setParam(IloCplex::NodeFileInd, 3); setParam(IloCplex::MIPDisplay, 4); setParam(IloCplex::MIPInterval, 1). No others.

    I apply cplex.getObjValue(), cplex.getBestObjValue() and cplex.getMIPRelativeGap() to get their results and the following are the results from a similar instance of my problem.

     

    Found incumbent of value 0.000000 after 0.00 sec. (0.52 ticks)
    Tried aggregator 1 time.
    MIP Presolve eliminated 10230 rows and 1 columns.
    Reduced MIP has 9185 rows, 12276 columns, and 34715 nonzeros.
    Reduced MIP has 3069 binaries, 0 generals, 0 SOSs, and 0 indicators.
    Presolve time = 0.06 sec. (29.16 ticks)
    Probing time = 0.00 sec. (2.01 ticks)
    Tried aggregator 1 time.
    Presolve time = 0.03 sec. (15.45 ticks)
    Probing time = 0.01 sec. (2.01 ticks)
    Clique table members: 1.
    MIP emphasis: balance optimality and feasibility.
    MIP search method: dynamic search.
    Parallel mode: deterministic, using up to 4 threads.
    Parallel mode: deterministic, using up to 2 threads for concurrent optimization.
    Tried aggregator 1 time.
    LP Presolve eliminated 1 rows and 2 columns.
    Reduced LP has 9184 rows, 12274 columns, and 34712 nonzeros.
    Presolve time = 0.02 sec. (7.54 ticks)
    Initializing dual steep norms . . .
     
    Iteration log . . .
    Iteration:     1   Dual objective     =         43714.699025
    Iteration:   446   Dual objective     =         27553.942094
    Iteration:   821   Dual objective     =         16431.641033
    Iteration:  1100   Dual objective     =         10347.128136
    Iteration:  1344   Dual objective     =         10118.905807
    Iteration:  1593   Dual objective     =          9797.705191
    Iteration:  1859   Dual objective     =          9380.070929
    Iteration:  2170   Dual objective     =          8805.984881
    Iteration:  2532   Dual objective     =          8614.028448
    Iteration:  2871   Dual objective     =          8526.990611
    Iteration:  3209   Dual objective     =          8470.954950
    Reinitializing dual norms . . .
    Initializing dual steep norms . . .
     
    Dual simplex solved model.
     
    Root relaxation solution time = 0.33 sec. (96.09 ticks)
     
            Nodes                                         Cuts/
       Node  Left     Objective  IInf  Best Integer    Best Bound    ItCnt     Gap
     
    *     0+    0                            0.0000    48388.7906     3467     --- 
    Found incumbent of value 0.000000 after 0.66 sec. (160.73 ticks)
    *     0+    0                         5496.4819    48388.7906     3467  780.36%
    Found incumbent of value 5496.481877 after 0.66 sec. (160.96 ticks)
          0     0     8456.4408  1410     5496.4819     8456.4408     3467   53.85%
    *     0+    0                         6588.8088     8456.4408     3467   28.35%
    Found incumbent of value 6588.808784 after 0.73 sec. (201.96 ticks)
    *     0+    0                         7350.5020     8456.4408     6072   15.05%
    Found incumbent of value 7350.502047 after 1.34 sec. (523.24 ticks)
          0     0     7900.8606  1149     7350.5020    Cuts: 2396     6072    7.49%
    *     0+    0                         7553.0993     7900.8606     6072    4.60%
    Found incumbent of value 7553.099254 after 1.45 sec. (574.48 ticks)
    *     0+    0                         7578.4884     7900.8606     7339    4.25%
    Found incumbent of value 7578.488402 after 1.97 sec. (812.75 ticks)

    ...

    Elapsed time = 27.68 sec. (8443.21 ticks, tree = 4.73 MB, solutions = 28)
       3551  1200     7640.4066   202     7640.2661     7646.1736    60198    0.08%
       3552  1201     7643.7642   108     7640.2661     7646.1736    60205    0.08%
       3553  1200        cutoff           7640.2661     7646.1736    60211    0.08%
       3554  1199     7640.3507   170     7640.2661     7646.1736    60217    0.08%
       3555  1200     7642.7772   100     7640.2661     7646.1736    60222    0.08%
       3556  1199        cutoff           7640.2661     7646.1736    60224    0.08%
       3557  1198        cutoff           7640.2661     7646.1736    60226    0.08%
       3558  1199     7641.8850    92     7640.2661     7646.1736    60246    0.08%
       3559  1198        cutoff           7640.2661     7646.1736    60253    0.08%
       3560  1197        cutoff           7640.2661     7646.1736    60277    0.08%
    Elapsed time = 27.68 sec. (8445.22 ticks, tree = 4.73 MB, solutions = 28)
       3561  1198     7644.6238   227     7640.2661     7646.1736    60292    0.08%
    *  3562+  798                         7640.5141     7645.5810    66126    0.07%
    Found incumbent of value 7640.514062 after 29.83 sec. (9288.16 ticks)
     
    Implied bound cuts applied:  1725
    Flow cuts applied:  161
    Mixed integer rounding cuts applied:  754
    Zero-half cuts applied:  105
    Gomory fractional cuts applied:  73
     
    Root node processing (before b&c):
      Real time             =    6.71 sec. (2843.56 ticks)
    Parallel b&c, 4 threads:
      Real time             =   36.69 sec. (11409.65 ticks)
      Sync time (average)   =    0.01 sec.
      Wait time (average)   =    0.02 sec.
                              ------------
    Total (root+branch&cut) =   43.40 sec. (14253.21 ticks)
    Solution Status
    Optimal
    ******************
    OptimalTol
    Final No of Nodes
    3562
    Final No of Nodes Left
    799
     
    Objective Value = 7640.51      //from cplex.getObjValue()
    Best Objective Value = 7641.17      // from cplex.getBestObjValue() 
    MIPRelativeGap = 8.5491e-005       //cplex.getMIPRelativeGap()

     

    The return from cplex.getMIPRelativeGap() is significant, which is less than default 0.01%. But the node output information stops at node 3562 with gap 0.07%.

    Attached is the model.sav file.

     

     

     


    #CPLEXOptimizers
    #DecisionOptimization


  • 7.  Re: cplex stops as optimal without reaching terminating optimality gap tolerance

    Posted 04/02/14 08:01 AM

    I think what you are observing is still correct/expected. CPLEX terminates with a gap of 8e-5 which is smaller than 1e-4, hence it is fine for CPLEX to terminate with status OptimalTol (optimal within the specified tolerances).

    The gap 0.07% in the log is most likely due to thread synchronization: In deterministic multi-threading the different threads do not always synchronize solution information immediately. Instead they synchronize information periodically at so called "sync points". This means that between two sync points a thread may have slightly outdated information and may therefore print slightly outdated information to the log. The information a thread prints is never wrong but may not be as good as it could be. In your case I suppose that the value for the dual bound printed in the log is in fact a little larger than what it printed in the log (namely 7641.17). Right after CPLEX finds the incumbent at node 3562 the threads synchronize, learn about the better dual bound and recognize that they can stop immediately.

    You could set the thread count to 1 (parameter IloCplex::Threads) and check if the log then makes more sense to you.


    #CPLEXOptimizers
    #DecisionOptimization