Model.solve_details.best_bound is set to NaN if time limit is exceeded before finding an integer solution #17
Description
I find that Model.solve_details.best_bound is set to NaN if the time limit is exceeded before finding an integer solution, even when the CPLEX log is reporting finite best bounds.
For my application, I need to record the best bound, even for scenarios where CPLEX fails to find an integer solution. As a temporary workaround, I have written a progress listener that records the best bound.
I don't have a minimal reproducer for this, but you can reproduce it using my open-source code here: https://github.com/m4opt/m4opt
You'll need the attached input file, 27.fits.gz. Here is the command and its output:
$ m4opt schedule --mission=uvex --bandpass=NUV --deadline=6hour --timelimit=1min --memory=10GiB --absmag-mean=-14 --absmag-stdev=1 --exptime-min=300s --nside=128 --cutoff=0.1 --jobs=12 27.fits.gz example.ecsv
Checking license ...
License found. [0.01 s]
Version identifier: 22.1.1.0 | 2023-06-15 | d64d5bd77
CPXPARAM_Read_DataCheck 1
CPXPARAM_Threads 12
CPXPARAM_Parallel -1
CPXPARAM_MIP_Strategy_File 3
CPXPARAM_Emphasis_MIP 1
CPXPARAM_MIP_Pool_Capacity 0
CPXPARAM_TimeLimit 60
CPXPARAM_WorkMem 10240
CPXPARAM_MIP_Tolerances_LowerCutoff 0.10000000000000001
CPXPARAM_WorkDir
"/var/folders/w5/pgrtm0vs1psb88v7z4fz0lh084mbdz/T"
MIP Presolve eliminated 262 redundant SOS constraints.
Tried aggregator 2 times.
MIP Presolve eliminated 15944 rows and 8192 columns.
MIP Presolve added 19248 rows and 4812 columns.
MIP Presolve modified 1439 coefficients.
Aggregator did 6396 substitutions.
Reduced MIP has 25963 rows, 27430 columns, and 110177 nonzeros.
Reduced MIP has 5096 binaries, 0 generals, 4900 SOSs, and 310 indicators.
Presolve time = 0.08 sec. (205.65 ticks)
Probing fixed 458 vars, tightened 4016 bounds.
Probing time = 0.01 sec. (17.48 ticks)
Cover probing fixed 187 vars, tightened 638 bounds.
Tried aggregator 3 times.
Detecting symmetries...
MIP Presolve eliminated 1297 rows and 1650 columns.
MIP Presolve modified 1407 coefficients.
Aggregator did 422 substitutions.
Reduced MIP has 24244 rows, 25358 columns, and 103618 nonzeros.
Reduced MIP has 4545 binaries, 0 generals, 4900 SOSs, and 306 indicators.
Presolve time = 0.07 sec. (118.51 ticks)
Probing fixed 102 vars, tightened 1918 bounds.
Probing time = 0.01 sec. (13.23 ticks)
Cover probing fixed 0 vars, tightened 142 bounds.
Clique table members: 6555.
Problem contains 2 user cuts.
MIP emphasis: integer feasibility.
MIP search method: dynamic search.
Parallel mode: opportunistic, using up to 12 threads.
Root relaxation solution time = 0.21 sec. (546.79 ticks)
Nodes Cuts/
Node Left Objective IInf Best Integer Best Bound ItCnt Gap
0 0 0.4052 2389 0.4052 99
0 0 0.2273 366 Cuts: 6162 17859
0 0 0.2263 322 Cuts: 3210 24042
0 0 0.2202 413 Cuts: 687 36883
Detecting symmetries...
0 2 0.2202 412 0.2202 36884
Elapsed time = 6.94 sec. (22808.13 ticks, tree = 0.02 MB)
4 6 0.2201 405 0.2201 36925
10 12 0.2201 394 0.2201 36956
15 17 0.2203 393 0.2201 38248
21 22 0.2203 393 0.2201 38454
29 30 0.2203 389 0.2201 38472
36 36 0.2203 385 0.2201 38495
42 41 0.2203 387 0.2201 38665
45 7 0.2197 290 0.2201 39109
47 8 0.2201 375 0.2201 37717
50 49 0.2165 348 0.2201 45573
Elapsed time = 9.08 sec. (28347.29 ticks, tree = 0.63 MB)
62 59 0.2161 353 0.2201 52197
88 66 0.2138 296 0.2201 54589
155 101 0.1836 180 0.2201 112184
273 223 0.1809 87 0.2201 123095
415 246 0.1743 130 0.2201 124428
612 557 0.2151 398 0.2201 173719
743 510 0.1928 191 0.2201 160244
831 684 0.1514 86 0.2201 209635
964 767 0.1079 31 0.2201 215087
1060 947 0.1001 30 0.2201 257872
Elapsed time = 13.13 sec. (37968.20 ticks, tree = 11.33 MB)
1155 1080 0.1840 304 0.2201 304615
1384 1075 0.1346 134 0.2201 305137
1577 1252 0.1246 165 0.2201 320795
1869 1614 0.1135 96 0.2201 387471
2179 1698 0.1000 35 0.2201 392551
2492 2196 0.1729 227 0.2201 468510
2723 2066 0.1510 325 0.2201 420668
2932 2567 0.1821 254 0.2201 498807
3213 2719 0.1370 486 0.2201 510300
3521 2898 0.1264 224 0.2201 521434
Elapsed time = 17.78 sec. (47542.46 ticks, tree = 32.27 MB)
3813 3457 0.1066 294 0.2201 551086
4093 3496 0.1294 448 0.2201 564382
4207 3456 0.1870 423 0.2201 561032
Performing restart 1
Repeating presolve.
Tried aggregator 1 time.
MIP Presolve eliminated 412 rows and 271 columns.
MIP Presolve modified 8668 coefficients.
Reduced MIP has 23832 rows, 25087 columns, and 99604 nonzeros.
Reduced MIP has 4439 binaries, 0 generals, 4900 SOSs, and 306 indicators.
Presolve time = 0.03 sec. (59.14 ticks)
Tried aggregator 1 time.
MIP Presolve eliminated 65 rows and 132 columns.
MIP Presolve modified 1414 coefficients.
Reduced MIP has 23767 rows, 24955 columns, and 99032 nonzeros.
Reduced MIP has 4403 binaries, 0 generals, 4900 SOSs, and 306 indicators.
Presolve time = 0.04 sec. (64.58 ticks)
Represolve time = 0.19 sec. (571.05 ticks)
Problem contains 2 user cuts.
4216 0 0.1772 556 Cuts: 860 746454
4216 0 0.1704 596 Cuts: 1001 749073
4216 0 0.1674 541 Cuts: 773 749886
4216 2 0.1674 541 0.1674 749886
4333 51 0.1664 604 0.1673 751271
4426 213 0.1661 590 0.1673 757949
4467 243 0.1678 579 0.1673 758514
4493 269 0.1677 616 0.1673 758661
4544 338 0.1656 330 0.1673 786342
4628 360 0.1601 492 0.1673 772801
Elapsed time = 27.69 sec. (78095.74 ticks, tree = 12.02 MB)
4689 416 0.1658 484 0.1673 804419
4739 370 0.1675 527 0.1673 786473
4802 530 0.1598 468 0.1673 811086
4837 550 0.1590 410 0.1673 811975
4891 546 0.1539 473 0.1673 811084
4947 686 0.1531 421 0.1673 823799
4995 853 0.1679 570 0.1673 856075
5073 817 0.1527 367 0.1673 828057
5135 841 0.1512 454 0.1673 829624
5211 811 0.1399 343 0.1673 829648
Elapsed time = 31.98 sec. (87734.75 ticks, tree = 41.70 MB)
5329 980 0.1303 313 0.1673 858809
5440 1144 0.1302 287 0.1673 860115
5560 990 0.1339 243 0.1673 858254
5674 1241 0.1243 283 0.1673 860598
5786 1410 0.1159 265 0.1673 907506
5921 1458 0.1142 235 0.1673 907695
6075 1507 0.1112 208 0.1673 907904
6212 1282 0.1115 146 0.1673 907050
6330 1533 0.1088 129 0.1673 952040
6488 2072 0.1206 321 0.1673 1034213
Elapsed time = 36.41 sec. (97321.01 ticks, tree = 53.79 MB)
6611 1815 0.1524 441 0.1673 983259
6739 2134 0.1139 249 0.1673 1035109
6875 2543 0.1142 168 0.1673 1158923
7010 2363 0.1109 74 0.1673 1133582
7127 2405 0.1070 40 0.1673 1133961
7230 2495 0.1582 481 0.1673 1143351
7298 2819 cutoff 0.1673 1263913
7426 2540 0.1302 299 0.1673 1158853
7659 2594 0.1237 217 0.1673 1159266
7829 2816 0.1350 283 0.1673 1264903
Elapsed time = 41.09 sec. (106926.30 ticks, tree = 61.65 MB)
7885 3122 0.1072 170 0.1673 1347710
7943 3158 0.1072 141 0.1673 1347820
8019 3195 0.1071 103 0.1673 1347875
8108 3230 0.1062 72 0.1673 1348195
8200 3077 0.1123 85 0.1673 1330755
8285 2978 0.1526 625 0.1673 1310357
8364 3378 0.1042 161 0.1673 1389531
8440 3182 0.1265 352 0.1673 1351715
8517 3213 0.1227 431 0.1673 1352500
8604 3502 0.1034 54 0.1673 1394314
Elapsed time = 44.93 sec. (116528.94 ticks, tree = 91.79 MB)
8664 3550 0.1020 101 0.1673 1395117
8709 3201 0.1624 855 0.1673 1390325
8710 10 0.1690 814 0.1673 771954
8711 2929 0.1684 876 0.1673 1282709
8712 5 0.1667 876 0.1673 785185
8713 3253 0.1685 775 0.1673 1397342
Performing restart 2
Repeating presolve.
Tried aggregator 1 time.
MIP Presolve eliminated 28 rows and 54 columns.
MIP Presolve modified 847 coefficients.
Reduced MIP has 23739 rows, 24901 columns, and 98943 nonzeros.
Reduced MIP has 4387 binaries, 0 generals, 4900 SOSs, and 306 indicators.
Presolve time = 0.03 sec. (48.10 ticks)
Tried aggregator 1 time.
MIP Presolve modified 736 coefficients.
Reduced MIP has 23739 rows, 24901 columns, and 98943 nonzeros.
Reduced MIP has 4387 binaries, 0 generals, 4900 SOSs, and 306 indicators.
Presolve time = 0.04 sec. (63.12 ticks)
Represolve time = 0.19 sec. (549.83 ticks)
Problem contains 2 user cuts.
8714 0 0.1640 900 Cuts: 1186 1708378
8714 0 0.1629 1005 Cuts: 1197 1709123
8714 0 0.1622 967 Cuts: 1163 1709950
8714 2 0.1622 967 0.1622 1709950
8720 5 0.1620 744 0.1622 1711417
8734 28 0.1561 669 0.1622 1773522
8751 38 0.1485 529 0.1622 1775761
Elapsed time = 60.02 sec. (155401.36 ticks, tree = 0.21 MB)
8759 4 0.1601 947 0.1622 1733320
8760 7 0.1615 640 0.1622 1713420
8771 26 0.1603 696 0.1622 1771085
8782 37 0.1577 657 0.1622 1773577
8801 13 0.1589 814 0.1622 1768013
8811 23 0.1588 806 0.1622 1768651
Clique cuts applied: 339
Cover cuts applied: 1103
Implied bound cuts applied: 1742
Flow cuts applied: 288
Mixed integer rounding cuts applied: 347
Zero-half cuts applied: 7
Gomory fractional cuts applied: 137
User cuts applied: 1
Root node processing (before b&c):
Real time = 6.64 sec. (22677.54 ticks)
Parallel b&c, 12 threads:
Real time = 53.43 sec. (147220.57 ticks)
Sync time (average) = 2.87 sec.
Wait time (average) = 0.03 sec.
------------
Total (root+branch&cut) = 60.07 sec. (169898.11 ticks)
✓ loading sky map 0:00:00
✓ propagating orbit 0:00:00
✓ evaluating field of regard 0:00:00
✓ calculating footprints 0:00:00
✓ evaluating exposure time map 0:00:01
✓ calculating slew times 0:00:00
✓ assembling MILP model 0:00:00
✓ adding 2282 continuous variables 0:00:00
✓ adding 50 binary variables 0:00:00
✓ adding 100 continuous variables 0:00:00
✓ adding 50 semicontinuous variables 0:00:00
✓ adding 164 continuous variables 0:00:00
✓ adding field of regard constraints 0:00:00
✓ adding cadence constraints 0:00:00
✓ adding slew constraints 0:00:00
✓ adding exposure time constraints 0:00:00
✓ adding coverage constraints 0:00:00
✓ adding cuts 0:00:00
✓ adding objective function 0:00:00
✓ solving MILP model 0:01:00
✓ writing results 0:00:00