Infeasible instead of 5552530

[christoph-cullmann]

Older versions, e.g. from August last year still compute 5552530, current master results in infeasible.

value_5552530.lp.txt

[jjhforrest]

Coding in CglPreProcess needs more thinking. Some code switched off for now. Thanks.

[christoph-cullmann]

Thanks for the fast feedback ;)

Do I misunderstand that or should the last commit to master from today solve this? If yes, at least for me, cbc still runs into infeasibility.

[christoph-cullmann]

TwoMirCuts seems to cause the infeasibility if I am not wrong.

[jjhforrest]

Could not duplicate your error, but found a case where TwoMir was borderline. I have put a small tweak in dual which fixed my problem (master).

[christoph-cullmann]

Hmm, thanks for taking a look. Just pulled master, still get

cbc test/value_5552530.lp
Welcome to the CBC MILP Solver
Version: trunk
Build Date: Sep  1 2023
command line - test/value_5552530.lp (default strategy 1)
 CoinLpIO::readLp(): Maximization problem reformulated as minimization
Coin0009I Switching back to maximization to get correct duals etc
Continuous objective value is 5.55282e+06 - 0.680129 seconds
Cgl0003I 13 fixed, 13629 tightened bounds, 0 strengthened rows, 6 substitutions
Cgl0003I 14 fixed, 6389 tightened bounds, 0 strengthened rows, 4 substitutions
Cgl0003I 4 fixed, 5949 tightened bounds, 0 strengthened rows, 4 substitutions
Cgl0003I 2 fixed, 5333 tightened bounds, 0 strengthened rows, 4 substitutions
Cgl0003I 0 fixed, 3740 tightened bounds, 0 strengthened rows, 4 substitutions
Cgl0003I 0 fixed, 3560 tightened bounds, 0 strengthened rows, 0 substitutions
Cgl0003I 2 fixed, 4701 tightened bounds, 0 strengthened rows, 0 substitutions
Cgl0003I 8 fixed, 4380 tightened bounds, 0 strengthened rows, 0 substitutions
Cgl0003I 0 fixed, 2845 tightened bounds, 0 strengthened rows, 0 substitutions
Cgl0003I 1 fixed, 4572 tightened bounds, 0 strengthened rows, 1 substitutions
Cgl0003I 3 fixed, 3591 tightened bounds, 0 strengthened rows, 0 substitutions
Cgl0003I 0 fixed, 1715 tightened bounds, 0 strengthened rows, 0 substitutions
Cgl0003I 0 fixed, 1666 tightened bounds, 0 strengthened rows, 0 substitutions
Cgl0003I 0 fixed, 1317 tightened bounds, 0 strengthened rows, 0 substitutions
Cgl0003I 0 fixed, 738 tightened bounds, 0 strengthened rows, 0 substitutions
Cgl0003I 0 fixed, 245 tightened bounds, 0 strengthened rows, 0 substitutions
Cgl0003I 0 fixed, 80 tightened bounds, 0 strengthened rows, 0 substitutions
Cgl0004I processed model has 10779 rows, 29882 columns (29882 integer (1507 of which binary)) and 79680 elements
Coin3009W Conflict graph built in 0.002 seconds, density: 0.001%
Cgl0015I Clique Strengthening extended 0 cliques, 0 were dominated
Cbc0031I 160 added rows had average density of 4.975
Cbc0013I At root node, 546 cuts changed objective from 5552795 to 5429406.9 in 1 passes
Cbc0014I Cut generator 0 (Probing) - 2 row cuts average 2.0 elements, 1 column cuts (1 active)  in 0.056 seconds - new frequency is -100
Cbc0014I Cut generator 1 (Gomory) - 169 row cuts average 5.4 elements, 0 column cuts (0 active)  in 0.059 seconds - new frequency is 1
Cbc0014I Cut generator 2 (Knapsack) - 0 row cuts average 0.0 elements, 0 column cuts (0 active)  in 0.005 seconds - new frequency is -100
Cbc0014I Cut generator 3 (Clique) - 0 row cuts average 0.0 elements, 0 column cuts (0 active)  in 0.000 seconds - new frequency is -100
Cbc0014I Cut generator 4 (OddWheel) - 0 row cuts average 0.0 elements, 0 column cuts (0 active)  in 0.001 seconds - new frequency is -100
Cbc0014I Cut generator 5 (MixedIntegerRounding2) - 0 row cuts average 0.0 elements, 0 column cuts (0 active)  in 0.001 seconds - new frequency is -100
Cbc0014I Cut generator 6 (FlowCover) - 0 row cuts average 0.0 elements, 0 column cuts (0 active)  in 0.002 seconds - new frequency is -100
Cbc0014I Cut generator 7 (TwoMirCuts) - 375 row cuts average 19.0 elements, 0 column cuts (0 active)  in 0.059 seconds - new frequency is -100
Cbc0001I Search completed - best objective -1e+50, took 19 iterations and 0 nodes (5.15 seconds)
Cbc0035I Maximum depth 0, 0 variables fixed on reduced cost
Cuts at root node changed objective from 5.55279e+06 to 5.42941e+06
Probing was tried 1 times and created 3 cuts of which 0 were active after adding rounds of cuts (0.056148 seconds)
Gomory was tried 1 times and created 169 cuts of which 0 were active after adding rounds of cuts (0.05879 seconds)
Knapsack was tried 1 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.005303 seconds)
Clique was tried 1 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.000112 seconds)
OddWheel was tried 1 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.001038 seconds)
MixedIntegerRounding2 was tried 1 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.000818 seconds)
FlowCover was tried 1 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.0022 seconds)
TwoMirCuts was tried 1 times and created 375 cuts of which 0 were active after adding rounds of cuts (0.059305 seconds)
ZeroHalf was tried 1 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.289542 seconds)

Result - Problem proven infeasible
No feasible solution found
Enumerated nodes:               0
Total iterations:               19
Time (CPU seconds):             5.15316
Time (Wallclock seconds):       5.26638
Total time (CPU seconds):       5.26204   (Wallclock seconds):       5.39197

[jjhforrest]

Odd - your log

Welcome to the CBC MILP Solver
Version: trunk
Build Date: Sep 1 2023
command line - test/value_5552530.lp (default strategy 1)
CoinLpIO::readLp(): Maximization problem reformulated as minimization
Coin0009I Switching back to maximization to get correct duals etc
Continuous objective value is 5.55282e+06 - 0.680129 seconds
Cgl0003I 13 fixed, 13629 tightened bounds, 0 strengthened rows, 6 substitutions
I get
Welcome to the CBC MILP Solver
Version: Devel (unstable)
Build Date: Sep 1 2023
command line - /tmp/value_5552530.lp (default strategy 1)
CoinLpIO::readLp(): Maximization problem reformulated as minimization
Coin0009I Switching back to maximization to get correct duals etc
Continuous objective value is 5.55282e+06 - 1.58349 seconds
Cgl0003I 21 fixed, 13909 tightened bounds, 0 strengthened rows, 7 substitutions

Where does "trunk" come from?

[christoph-cullmann]

Hmm, that diff might be because I build via CMake and not the normal build system. Will need to check if some other defines differ, too, thanks for the hint!

[christoph-cullmann]

Hmmm, updated the compiler, to LLVM 17, this happens now even for the older cbc version we have and not just master like it is now. Not sure how to debug this best, but it seems to depend on the compiler. We did use -ffp-model=strict, tried to remove that but didn't change it.

[christoph-cullmann]

I bisected now all repositories we use.
The example above works with current master of CoinUtils, Osi, Clp, Cgl and Cbc , if I revert

coin-or/CoinUtils@9afa672

[jjhforrest]

The fault is not in CoinPresolveDual - it is just that those changes made a difference to the preprocessed model. Trying many different options I have managed to get a preprocessed model that goes wrong with my optimized code. The fault does seem to be a tolerance problem in CglTwomir. It creates the basis for a cut
(gdb) p *constraint
$30 = {nz = 126, max_nz = 126, coeff = 0x55555a834780,
index = 0x55555a8338b0, rhs = 37037040000.500145, sense = 69 'E'}
(gdb) p constraint->coeff[0]@12
$37 = {1, 1, 1, 1, -1, 1, -1, -1, -1, 1, -1, 1}

You will notice the very large rhs
After subtracting out stuff and scaling
(gdb) p *c
$38 = {nz = 126, max_nz = 126, coeff = 0x55555895a9a0,
index = 0x555555fac160, rhs = 0.50000381469726562, sense = 71 'G'}
(gdb) p c->coeff[0]@12
$39 = {0.50000381469726562, 0.50000381469726562, 0.50000381469726562,
0.50000381469726562, -0.50000381469726562, 0.50000381469726562,
-0.50000381469726562, -0.50000381469726562, -0.50000381469726562,
0.50000381469726562, -0.50000381469726562, 0.50000381469726562}
which looks plausible but is a bad cut (just
BAD cut
Cut with 126 coefficients, cuts off known solutions by 3.8147e-06, lo=0.500004, ub=1.79769e+308

I am looking at best way to fix. This seems to fix and is in master
-- a/src/CglTwomir/CglTwomir.cpp
+++ b/src/CglTwomir/CglTwomir.cpp
@@ -1618,6 +1618,11 @@ DGG_generateCutsFromBase( DGG_constraint_t *orig_base,
if (orig_base->sense == 'L') return 0;
if (orig_base->nz == 0) return 0;

+#define CGL_TWOMIR_LARGE_RHS 1.0e10
+#ifdef CGL_TWOMIR_LARGE_RHS

• if (fabs(orig_base->rhs) > CGL_TWOMIR_LARGE_RHS )
• return 0;
  +#endif
  rval = DGG_transformConstraint(data, &x, &rc, &isint, orig_base);

[christoph-cullmann]

That change in master seems to fix our issues, with both versions of LLVM/clang we use, for the above ILP.
With the new LLVM/clang I still run into one timeout with another model, but I guess that is not related.

[jjhforrest]

Did the timeout one work well with previous code? The fix I put in was totally safe, but maybe one could just have weakened the cut a bit to allow for large value and many elements. If it did work well I could look further - or even better someone who knows that bit of code could look at problem.

[christoph-cullmann]

No, the timeout occurred already before with the old code, just with the LLVM update, seems to be some interaction with -reduce=on, without that, it is fast, but I need that in general.

value_29051516.lp.txt

The standalone cbc solver has no issues, we drive it with

    /**
     * deactivate all cuts first and then activate the ones we know are good below one by one
     */
    "-cuts=off",

    /**
     * Gomory
     *   used A LOT
     */
    "-gomory=on",

    /**
     * Gomory(2)
     *   alternative variant of Gomory
     *   fixes timeout for e.g. value_530288.lp
     *   kills e.g. value_87454.lp
     */
    "-gmi=on",

    /**
     * TwoMirCuts
     *   needed as "on" for e.g. value_24093348.lp to avoid timeout even on Linux
     */
    "-two=on",

    /**
     * ZeroHalf
     *   needed as "on" for e.g. value_87454.lp to avoid timeout even on Linux
     */
    "-ZeroHalf=on",

    /**
     * Reduce-and-split
     *   improves A LOT of problems, e.g. makes value_6054.lp solvable at all without cplex
     */
    "-reduce=on",

    /**
     * enable some diving heuristics
     * e.g. this fixes issue with value_2266800625.lp, with just DivingL we have here
     * on Windows 2266800525 as result
     */
    "-DivingC=on",
    "-DivingL=on",
    "-DivingS=on",

and that leads to the timeout.

[christoph-cullmann]

old LLVM 16 compiled variant

./clpsolve test/value_29051516.lp
This is clpsolve, Release: 23.10i, Build: 13993829, Tag: master, Branch: master
(c) Copyright AbsInt Angewandte Informatik GmbH
Progress: [15:44:57]: Reading lp file 'test/value_29051516.lp'...
Progress: [15:44:57]: Finished reading lp file.
Progress: [15:44:59]: processed model has 12911 rows, 40032 columns (40032 integer (98 of which binary)) and 160374 elements
Progress: [15:45:00]: Integer solution of 29051516 found by DiveAny after 109 iterations and 0 nodes (2.88 seconds)
Progress: [15:45:00]: 4 added rows had average density of 3236.25
Progress: [15:45:00]: At root node, 4 cuts changed objective from 29051516 to 29051516 in 4 passes
Progress: [15:45:00]: Cut generator 0 (Gomory) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.121 seconds - new frequency is 1000
Progress: [15:45:00]: Cut generator 1 (Reduce-and-split) - 8 row cuts average 3149.1 elements, 0 column cuts (0 active) in 0.137 seconds - new frequency is 1
Progress: [15:45:00]: Cut generator 2 (Gomory(2)) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.245 seconds - new frequency is 1000
Progress: [15:45:00]: Cut generator 3 (TwoMirCuts) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.168 seconds - new frequency is 1000
Progress: [15:45:00]: Cut generator 4 (ZeroHalf) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.164 seconds - new frequency is 1000
Progress: [15:45:00]: Search completed - best objective 29051516, took 109 iterations and 0 nodes (2.95 seconds)
Progress: [15:45:00]: Maximum depth 0, 0 variables fixed on reduced cost
Progress: [15:45:00]: Cuts at root node changed objective from 2.90515e+07 to 2.90515e+07
Progress: [15:45:00]: Gomory was tried 4 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.120912 seconds)
Progress: [15:45:00]: Reduce-and-split was tried 4 times and created 8 cuts of which 0 were active after adding rounds of cuts (0.137497 seconds)
Progress: [15:45:00]: Gomory(2) was tried 4 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.244693 seconds)
Progress: [15:45:00]: TwoMirCuts was tried 4 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.168067 seconds)
Progress: [15:45:00]: ZeroHalf was tried 4 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.164067 seconds)
Progress: [15:45:00]: Result - Optimal solution found
Progress: [15:45:00]: Objective value: 29051516
Enumerated nodes: 0
Total iterations: 109
Time (CPU seconds): 3.0232
Time (Wallclock seconds): 3.07236
Note: Value of objective function: 29051516.
Note: Solving succeeded.

vs. new LLVM 17 binary

./clpsolve test/value_29051516.lp
This is clpsolve, Release: 23.04i, Build: 13993829, Tag: bug/35369.17.0.3, Branch: bug/35369.17.0.3
(c) Copyright AbsInt Angewandte Informatik GmbH
Progress: [15:49:31]: Reading lp file 'test/value_29051516.lp'...
Progress: [15:49:31]: Finished reading lp file.
Progress: [15:49:33]: processed model has 12911 rows, 40032 columns (40032 integer (98 of which binary)) and 160374 elements
Progress: [15:49:35]: 2 added rows had average density of 2630
Progress: [15:49:35]: At root node, 2 cuts changed objective from 29051516 to 29051516 in 2 passes
Progress: [15:49:35]: Cut generator 0 (Gomory) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.085 seconds - new frequency is 1000
Progress: [15:49:35]: Cut generator 1 (Reduce-and-split) - 2 row cuts average 2630.0 elements, 0 column cuts (0 active) in 0.068 seconds - new frequency is 1
Progress: [15:49:35]: Cut generator 2 (Gomory(2)) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.168 seconds - new frequency is 1000
Progress: [15:49:35]: Cut generator 3 (TwoMirCuts) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.110 seconds - new frequency is 1000
Progress: [15:49:35]: Cut generator 4 (ZeroHalf) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.082 seconds - new frequency is 1000
Progress: [15:49:36]: After 0 nodes, 1 on tree, -1e+50 best solution, best possible 29051516 (4.68 seconds)
Progress: [15:49:37]: After 5 nodes, 6 on tree, -1e+50 best solution, best possible 29051516 (5.45 seconds)
Progress: [15:49:37]: After 18 nodes, 14 on tree, -1e+50 best solution, best possible 29051516 (6.19 seconds)
Progress: [15:49:38]: After 33 nodes, 21 on tree, -1e+50 best solution, best possible 29051516 (6.91 seconds)
Progress: [15:49:39]: After 46 nodes, 27 on tree, -1e+50 best solution, best possible 29051516 (7.62 seconds)
Progress: [15:49:40]: After 58 nodes, 34 on tree, -1e+50 best solution, best possible 29051516 (8.36 seconds)
Progress: [15:49:40]: After 71 nodes, 40 on tree, -1e+50 best solution, best possible 29051516 (9.09 seconds)
Progress: [15:49:41]: After 85 nodes, 47 on tree, -1e+50 best solution, best possible 29051516 (9.80 seconds)
Progress: [15:49:42]: After 98 nodes, 54 on tree, -1e+50 best solution, best possible 29051516 (10.55 seconds)
Progress: [15:49:42]: After 111 nodes, 59 on tree, -1e+50 best solution, best possible 29051516 (11.25 seconds)
Progress: [15:49:43]: Integer solution of 29049998 found after 2738 iterations and 113 nodes (11.43 seconds)
Progress: [15:49:43]: After 124 nodes, 61 on tree, 29049998 best solution, best possible 29051516 (12.00 seconds)
Progress: [15:49:44]: After 138 nodes, 65 on tree, 29049998 best solution, best possible 29051516 (12.71 seconds)
Progress: [15:49:45]: After 153 nodes, 72 on tree, 29049998 best solution, best possible 29051516 (13.42 seconds)
Progress: [15:49:45]: After 168 nodes, 74 on tree, 29049998 best solution, best possible 29051516 (14.15 seconds)
Progress: [15:49:46]: After 182 nodes, 78 on tree, 29049998 best solution, best possible 29051516 (14.86 seconds)
Progress: [15:49:47]: After 196 nodes, 81 on tree, 29049998 best solution, best possible 29051516 (15.58 seconds)
....