6
$\begingroup$

I ran a MIP model with a max solving time of 1800 seconds. CPLEX found the optimal solution (0.00 % MIP gap) after 710 seconds, but continued processing until it was stopped by the 1800 second limit.

When CPLEX already found the optimal solution after 710 seconds, why does it continue searching for more solutions? None of my cplex_settings specify that CPLEX should look for more solutions.

Edit

Regarding the settings, I had specified the dual to be solved with a mipgap of 0.05 and that the solver should stop on the first feasible solution it finds.

As requested, here's the log file.

Tried aggregator 2 times.
MIP Presolve eliminated 26030 rows and 33 columns.
MIP Presolve modified 262893 coefficients.
Aggregator did 42 substitutions.
Reduced MIP has 62815 rows, 53516 columns, and 1587796 nonzeros.
Reduced MIP has 53512 binaries, 4 generals, 0 SOSs, and 0 indicators.
Presolve time = 2.14 sec. (2937.68 ticks)
Probing time = 0.13 sec. (20.24 ticks)
Tried aggregator 1 time.
Detecting symmetries...
Elapsed time for symmetry detection = 6.77 sec. (10008.46 ticks)
Elapsed time for symmetry detection = 16.19 sec. (20008.49 ticks)
Elapsed time for symmetry detection = 25.37 sec. (30012.78 ticks)
Found 9.054173e+11898 symmetric permutations.
Reduced MIP has 62815 rows, 53516 columns, and 1587796 nonzeros.
Reduced MIP has 53512 binaries, 4 generals, 0 SOSs, and 0 indicators.
Presolve time = 30.26 sec. (35629.93 ticks)
Probing time = 0.06 sec. (20.23 ticks)
Clique table members: 466439.
MIP emphasis: balance optimality and feasibility.
MIP search method: dynamic search.
Parallel mode: deterministic, using up to 32 threads.
Parallel mode: deterministic, using up to 4 threads for parallel tasks at root LP.
Root relaxation solution time = 17.76 sec. (18171.73 ticks)

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

      0     0      855.0000  2457                    855.0000        9         
      0     0      855.0000  2457                   Cuts: 348     2147         
      0     0      855.0000  2457                  Cuts: 1665     5558         
      0     0      855.0000  2457                    Cuts: 56     7056         
      0     0      855.0000  2457                  Cuts: 1017    10443         
Heuristic still looking.
Heuristic still looking.
      0     2      855.0000   667                    855.0000    10443         
Elapsed time = 306.25 sec. (294530.46 ticks, tree = 0.02 MB)
      1     3      855.0000   795                    855.0000    18020         
      2     4      855.0000  3440                    855.0000    66067         
      3     5      855.0000  3718                    855.0000    67202         
      4     6      855.0000  3602                    855.0000    69179         
      5     7      855.0000  3557                    855.0000    74325         
      6     4      855.0000  2023                    855.0000    46708         
      7     9      855.0000  2023                    855.0000   109975         
                                                  Impl Bds: 9                  
      9    11      855.0000  2052                    855.0000   110101         
     10    11      855.0000  1756                    855.0000   110596         
     12    10      855.0000  1995                    855.0000   110796         
                                                 Impl Bds: 14                  
Elapsed time = 518.58 sec. (437339.57 ticks, tree = 0.02 MB)
     13    12      855.0000  2040                    855.0000   122462         
                                                  Impl Bds: 4                  
     17    19      855.0000  1658                    855.0000   132306         
     28    29      855.0000  2275                    855.0000   134254         
     36    36      855.0000  1762                    855.0000   135234         
     40    38      855.0000  2070                    855.0000   136817         
                                                  Impl Bds: 5                  
     52    41      855.0000  2053                    855.0000   139011         
     69    47      855.0000  1872                    855.0000   139054         
     84    56      855.0000  1224                    855.0000   140198         
     97    64      855.0000  1514                    855.0000   141954         
    112    63      855.0000  1610                    855.0000   143802         
Elapsed time = 560.10 sec. (450652.24 ticks, tree = 0.64 MB)
    120    68      855.0000  1599                    855.0000   144665         
    135    82      855.0000  1030                    855.0000   144261         
    154    79      855.0000  1413                    855.0000   147082         
    175    64      855.0000  1581                    855.0000   144448         
    199    71      855.0000  1625                    855.0000   145780         
    226    77      855.0000  1565                    855.0000   146911         
    252   150      855.0000   962                    855.0000   157477         
    271   206      855.0000   499                    855.0000   168780         
    293    94      855.0000  1225                    855.0000   150152         
    325   305      855.0000  1218                    855.0000   195880         
                                                 Impl Bds: 36                  
Elapsed time = 590.45 sec. (460750.45 ticks, tree = 6.38 MB)
    355   303      855.0000  1901                    855.0000   205160         
    393   341      855.0000   263                    855.0000   222597         
                                                  Impl Bds: 7                  
    422   351      855.0000   266                    855.0000   223359         
    459   340      855.0000  1765                    855.0000   229009         
                                                  Impl Bds: 6                  
    496   393      855.0000   986                    855.0000   249289         
                                                  Impl Bds: 7                  
    526   415      855.0000   879                    855.0000   294571         
                                                 Impl Bds: 10                  
    551   423      855.0000  1023                    855.0000   295779         
    564   490      855.0000  1120                    855.0000   321459         
    577   553      855.0000   630                    855.0000   344859         
    599   565      855.0000  1530                    855.0000   348707         
                                                  Impl Bds: 5                  
Elapsed time = 617.79 sec. (470692.71 ticks, tree = 9.89 MB)
    623   570      855.0000  1480                    855.0000   349724         
    646   597      855.0000  1550                    855.0000   358851         
                                                  Impl Bds: 1                  
    666   603      855.0000  1261                    855.0000   359511         
    683   603      855.0000  1461                    855.0000   362218         
                                                  Impl Bds: 2                  
    720   626      855.0000  1457                    855.0000   371858         
    753   675      855.0000  1736                    855.0000   382238         
    778   636      855.0000  1921                    855.0000   374288         
    818   678      855.0000   374                    855.0000   377260         
                                                  Impl Bds: 1                  
    868   688      855.0000   409                    855.0000   377835         
    910   728      855.0000  1522                    855.0000   421008         
Elapsed time = 644.11 sec. (480482.47 ticks, tree = 16.47 MB)
    952   726      855.0000   557                    855.0000   421356         
    996   856      855.0000   365                    855.0000   441037         
   1023   872      855.0000  1420                    855.0000   465385         
   1060   864      855.0000   371                    855.0000   448495         
   1118   977      855.0000  1665                    855.0000   547515         
   1176   891      855.0000  1050                    855.0000   469575         
                                                  Impl Bds: 1                  
   1212  1052      855.0000   522                    855.0000   576274         
   1257  1028      855.0000   968                    855.0000   561070         
   1302  1150      855.0000   141                    855.0000   603276         
   1357  1076      855.0000  1360                    855.0000   585541         
Elapsed time = 666.73 sec. (490171.99 ticks, tree = 43.16 MB)
   1413  1183      855.0000   811                    855.0000   606493         
   1455  1193      855.0000   250                    855.0000   607126         
   1499  1212      855.0000   366                    855.0000   607395         
   1537  1304      855.0000   271                    855.0000   626288         
   1589  1359      855.0000   287                    855.0000   643970         
   1657  1369      855.0000   229                    855.0000   644953         
   1726  1288      855.0000   396                    855.0000   624415         
   1805  1403      855.0000   323                    855.0000   646346         
                                                  Impl Bds: 5                  
   1887  1365      855.0000   542                    855.0000   629803         
   1980  1422      855.0000   309                    855.0000   647506         
Elapsed time = 690.33 sec. (499926.05 ticks, tree = 64.50 MB)
   2069  1517      855.0000   332                    855.0000   684526         
   2174  1613      855.0000   202                    855.0000   694310         
   2285  1536      855.0000   307                    855.0000   685722         
   2396  1783      855.0000   327                    855.0000   709940         
   2505  1682      855.0000   930                    855.0000   698222         
   2616  2011      855.0000   305                    855.0000   743888         
   2727  2175      855.0000   365                    855.0000   759293         
   2848  2078      855.0000   280                    855.0000   746821         
   2962  2501      855.0000  1381                    855.0000   827067         
   3048  2261      855.0000   264                    855.0000   762486         
Elapsed time = 710.75 sec. (509516.88 ticks, tree = 99.71 MB)
*  3054+ 2043                          855.0000      855.0000             0.00%
Found incumbent of value 855.000000 after 710.82 sec. (509549.52 ticks)
   3147  2610      855.0000   291      855.0000      855.0000   833946    0.00%
   3211  2576      855.0000   249      855.0000      855.0000   833103    0.00%
   3250  2585      855.0000   278      855.0000      855.0000   833743    0.00%
   3271  2595      855.0000   326      855.0000      855.0000   834668    0.00%
   3281     5      855.0000  3277      855.0000      855.0000    99161    0.00%
   3283   500      855.0000  1692      855.0000      855.0000   357237    0.00%
                                                 Impl Bds: 21                  
   3284    32      855.0000  1570      855.0000      855.0000   135251    0.00%
   3286  2484      855.0000   577      855.0000      855.0000   812189    0.00%
   3287  2154      855.0000   148      855.0000      855.0000   758606    0.00%
   3288   903      855.0000  1334      855.0000      855.0000   497120    0.00%
Elapsed time = 752.34 sec. (527635.49 ticks, tree = 29.21 MB)
   3289  2347      855.0000   389      855.0000      855.0000   773394    0.00%
   3291  2437      855.0000   546      855.0000      855.0000   802675    0.00%
   3293   820      855.0000  1265      855.0000      855.0000   441684    0.00%
   3294   558      855.0000  1333      855.0000      855.0000   349517    0.00%
   3295   616      855.0000  1287      855.0000      855.0000   364916    0.00%
   3296  2086      855.0000   255      855.0000      855.0000   747431    0.00%
   3297  2517      855.0000  1046      855.0000      855.0000   829337    0.00%
   3298     6      855.0000  3637      855.0000      855.0000    67877    0.00%
   3299     7      855.0000  4466      855.0000      855.0000   141055    0.00%
                                                 Impl Bds: 19                  
                                                 Impl Bds: 69                  

GUB cover cuts applied:  421
Clique cuts applied:  179
Cover cuts applied:  25
Implied bound cuts applied:  159
Flow cuts applied:  100
Mixed integer rounding cuts applied:  1184
Zero-half cuts applied:  114

Root node processing (before b&c):
  Real time             =  304.73 sec. (293507.17 ticks)
Parallel b&c, 32 threads:
  Real time             = 1495.47 sec. (1264489.70 ticks)
  Sync time (average)   =  215.72 sec.
  Wait time (average)   =    0.00 sec.
                          ------------
Total (root+branch&cut) = 1800.20 sec. (1557996.87 ticks)
CPLEX 12.10.0.0: optimal integer solution; objective 855
1545023 MIP simplex iterations
3300 branch-and-bound nodes
```
Improve this question
$\endgroup$
14
  • 3
    $\begingroup$ can you show the log file $\endgroup$
    – user3680510
    Commented Aug 2, 2021 at 19:01
  • 2
    $\begingroup$ When running with multiple threads, it is possible for one thread to reach optimality while another thread is chugging along chewing on a node LP or something ... though it is hard to picture that going on for 1100 seconds. Did you use nondefault settings for the gap parameters? $\endgroup$
    – prubin ♦
    Commented Aug 2, 2021 at 19:01
  • 1
    $\begingroup$ I find it rather suspicious that simplex iteration count (ItCnt) is not monotone. I have never seen that before. The node count is monotone increasing, which is some comfort. Something to do with 32 threads? (I've never made it above four threads myself.) Bug? If possible, I would suggest upgrading to CPLEX 20.1 and retrying. $\endgroup$
    – prubin ♦
    Commented Aug 2, 2021 at 22:21
  • 1
    $\begingroup$ Ok, it's CPLEX 12.10. Perhaps there is a bug, e.g., in the symmetry detection part!? $\endgroup$
    – rasul
    Commented Aug 3, 2021 at 0:38
  • 1
    $\begingroup$ @Christian What happens when you turn off symmetry breaking? You can set this parameter to its default value of 0 to turn it off. $\endgroup$
    – rasul
    Commented Aug 3, 2021 at 0:48

1 Answer 1

Reset to default
5
$\begingroup$

As suggested, I'm synthesizing some comments into an "answer" ... although I'm not sure it actually answers anything.

First, small values for the gap parameters can sometimes result in CPLEX printing a gap value that rounds to zero in the log but still cranking away because the actual gap is slightly larger than the parameter value. Setting mipgap (relative gap tolerance) to 0.05 and leaving absmipgap (absolute tolerance) at the default 1e-6 should definitely have stopped CPLEX. (It stops when either, not necessarily both, conditions are met.)

Second, the iteration count in the log is not monotone, which it should be (there being no such thing as negative simplex pivots). Coupled with the fairly high thread count (32), I suspect that timing of thread might be a factor. Threads chewing on nodes communicate intermittently with the "one thread to rule them all", and do not know immediately when other threads have found a new incumbent or tightened the bound. Still, the time laps between reaching a zero gap and terminating is seriously out of whack, suggesting a possible bug.

Improve this answer
$\endgroup$

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.