Skip to main content

Improving model formulation and solving time

Answered
Koen Timmermans
Edited
  • Gurobi-versary
  • Conversationalist
  • Curious

Hi!

I have a task scheduling problem that I'm trying to solve using a MILP model. It closely resembles a VRPTW (Vehicle Routing Problem with Time Windows). The exact model formulation can be found over here. I'm using a rolling time horizon, so several "smaller" instances of this MILP formulation are used to run one "full" scenario. I have also included several Gurobi logs, together with the \(\texttt{.mps}\) and \(\texttt{.mst}\) files. They are all numbered accordingly, so log 08 belongs to \(\texttt{.mps}\) and \(\texttt{.mst}\) files 08. To speed up the problem-solving process, I have already done several things:

  • I only create decision variables that are "feasible." This has reduced the number of ij combinations by more than 90%. Additionally, there are many tasks that can only be performed by specific vehicles, which further reduces the number of ijk combinations by more than 95%. So, I have tried to make the model as "dense" as possible.

    Despite my effort to create a "dense" model, Gurobi still removes a lot in the presolve phase. This is of course nice, but I'm wondering about how thare are still so many rows and columns that can be removed?

  • I have tightly defined the lb and ub values of the continuous variables and the big M values used. I have also included some constraints that "fix" a variable if it is not "used". (Also see the "Tightening constraints" file via the link provided above.)

    Do these constraints (T1 to T5, together with G8a and G8b) look good to tighten the bounds of the variables?

  • I have tried to limit the coefficient statistics ranges.

    I believe that the ranges for "milp_model_08" are acceptable. However, the log of "milp_model_10" shows a very big Bounds range. I get this with several other runs as well. I would like to get rid of that, but I'm not sure what causes it. I think that it may have to do with my objective function. Objective function components 3, 4, and 5 are very small. I have included them to let Gurobi converge faster to a solution (see my provided MILP formulation). (The weight factors that I am currently using are w1 = 20, w2 = 500, w3 = 0.001, w4 = 45, w5 = 0.05.) Any suggestions on how to improve this are much appreciated!

  • I have written a heuristic to provide Gurobi with an initial feasible solution. It works well because it always produces an initial solution.

  • I have implemented two symmetry breaking constraints (see link above) to allow Gurobi to converge faster by skipping some solutions that result in the same objective value.
  • I am using the NoRelHeuristic to improve my MIPstart solution, which works quite good. The lower bound is often not great, but I know that that is a result of how the NoRelHeuristic works.

  • I have varied the MIPFocus parameter (1, 2, and 3) and the Heuristics parameter, but it doesn't make much of a difference. I could probably change the Method parameter to only use dual simplex, since the barrier algorithm is often interrupted as the model gets solved by the dual simplex algorithm, but this would not increase the gap closing performance. Moreover, the barrier log often shows quite a high number of dense columns. I guess that this isn't a problem if the model is solved via dual simplex, but does this indicate a numerical issue in my model? Furthermore, changing the Presolve parameter didn't result in much more presolving, and changing the Cuts parameter didn't result in a significant difference either.

I was wondering if you notice anything in the logs that stands out or have suggestions for what I could do to speed up the solving process / gap closing?

Below, I have included some snippets of the Gurobi logs with some questions from my side (the full logs can be found via the link above).

MILP model 08:

2023-08-03 15:37:03 INFO    : Set parameter NoRelHeurTime to value 376
2023-08-03 15:37:03 INFO    : Set parameter IntegralityFocus to value 1
2023-08-03 15:37:03 INFO    : Set parameter LogFile to value "Gurobi_log_8"
2023-08-03 15:37:03 INFO    : Set parameter MIPGapAbs to value 0.05
2023-08-03 15:37:03 INFO    : Set parameter TimeLimit to value 1800
2023-08-03 15:37:03 INFO    : Gurobi Optimizer version 10.0.1 build v10.0.1rc0 (win64)
2023-08-03 15:37:03 INFO    : 
2023-08-03 15:37:03 INFO    : CPU model: 11th Gen Intel(R) Core(TM) i7-11700 @ 2.50GHz, instruction set [SSE2|AVX|AVX2|AVX512]
2023-08-03 15:37:03 INFO    : Thread count: 8 physical cores, 16 logical processors, using up to 16 threads
2023-08-03 15:37:03 INFO    : 
2023-08-03 15:37:03 INFO    : Academic license - for non-commercial use only - registered to XXX
2023-08-03 15:37:03 INFO    : Optimize a model with 1313829 rows, 442000 columns and 6734888 nonzeros
2023-08-03 15:37:03 INFO    : Model fingerprint: 0x02cb2cbd
2023-08-03 15:37:03 INFO    : Variable types: 14470 continuous, 427530 integer (427530 binary)
2023-08-03 15:37:03 INFO    : Coefficient statistics:
2023-08-03 15:37:03 INFO    :   Matrix range     [2e-01, 1e+03]
2023-08-03 15:37:03 INFO    :   Objective range  [1e-03, 5e+02]
2023-08-03 15:37:03 INFO    :   Bounds range     [1e+00, 1e+03]
2023-08-03 15:37:03 INFO    :   RHS range        [1e+00, 3e+03]
2023-08-03 15:37:03 INFO    : 
2023-08-03 15:37:03 INFO    : Warning: Completing partial solution with 427385 unfixed non-continuous variables out of 427530
2023-08-03 15:37:05 INFO    : User MIP start produced solution with objective 40964.3 (2.04s)
2023-08-03 15:37:05 INFO    : Loaded user MIP start with objective 40964.3
2023-08-03 15:37:05 INFO    : Processed MIP start in 2.05 seconds (2.77 work units)
2023-08-03 15:37:05 INFO    : 
2023-08-03 15:37:10 INFO    : Presolve removed 1158304 rows and 373539 columns (presolve time = 5s) ...
2023-08-03 15:37:15 INFO    : Presolve removed 1158304 rows and 373970 columns (presolve time = 10s) ...
2023-08-03 15:37:20 INFO    : Presolve removed 1158304 rows and 373970 columns (presolve time = 15s) ...
2023-08-03 15:37:25 INFO    : Presolve removed 1194425 rows and 381195 columns (presolve time = 20s) ...
2023-08-03 15:37:30 INFO    : Presolve removed 1194425 rows and 381195 columns (presolve time = 25s) ...
2023-08-03 15:37:35 INFO    : Presolve removed 1199750 rows and 383843 columns (presolve time = 30s) ...
2023-08-03 15:37:35 INFO    : Presolve removed 1199503 rows and 383596 columns
2023-08-03 15:37:35 INFO    : Presolve time: 30.13s
2023-08-03 15:37:35 INFO    : Presolved: 114326 rows, 58404 columns, 1125858 nonzeros
2023-08-03 15:37:36 INFO    : Variable types: 4050 continuous, 54354 integer (54353 binary)
2023-08-03 15:37:36 INFO    : Starting NoRel heuristic
2023-08-03 15:37:36 INFO    : Found heuristic solution: objective 40963.329000
2023-08-03 15:37:37 INFO    : Found heuristic solution: objective 40962.579005
...
2023-08-03 15:44:01 INFO    : Found heuristic solution: objective 29414.540890
2023-08-03 15:44:01 INFO    : Elapsed time for NoRel heuristic: 385s (best bound 16482.7)
2023-08-03 15:44:01 INFO    : 
2023-08-03 15:44:01 INFO    : Deterministic concurrent LP optimizer: primal simplex, dual simplex, and barrier
2023-08-03 15:44:01 INFO    : Showing barrier log only...
2023-08-03 15:44:01 INFO    : 
2023-08-03 15:44:01 INFO    : Root barrier log...
2023-08-03 15:44:01 INFO    : 
2023-08-03 15:44:13 INFO    : Ordering time: 10.85s
2023-08-03 15:44:14 INFO    : Elapsed ordering time = 11s
2023-08-03 15:44:18 INFO    : Elapsed ordering time = 15s
2023-08-03 15:44:23 INFO    : Elapsed ordering time = 20s
2023-08-03 15:44:25 INFO    : Ordering time: 22.48s
2023-08-03 15:44:26 INFO    : 
2023-08-03 15:44:26 INFO    : Barrier statistics:
2023-08-03 15:44:26 INFO    :  Dense cols : 786
2023-08-03 15:44:27 INFO    :  AA' NZ     : 1.083e+07
2023-08-03 15:44:27 INFO    :  Factor NZ  : 2.371e+08 (roughly 2.0 GB of memory)
2023-08-03 15:44:27 INFO    :  Factor Ops : 1.208e+12 (roughly 6 seconds per iteration)
2023-08-03 15:44:27 INFO    :  Threads    : 6
2023-08-03 15:44:37 INFO    : 
2023-08-03 15:44:37 INFO    :                   Objective                Residual
2023-08-03 15:44:37 INFO    : Iter       Primal          Dual         Primal    Dual     Compl     Time
2023-08-03 15:44:37 INFO    :    0   4.68824959e+06 -9.18880133e+06  3.86e+05 9.14e-01  1.68e+03   455s
2023-08-03 15:44:45 INFO    :    1   3.51865510e+06 -1.08255534e+07  2.88e+05 5.80e+00  1.20e+03   462s
2023-08-03 15:44:52 INFO    :    2   2.63480041e+06 -1.07845286e+07  2.15e+05 4.09e+00  8.61e+02   469s
2023-08-03 15:45:00 INFO    :    3   1.22790616e+06 -1.00118907e+07  9.76e+04 5.33e+00  4.03e+02   477s
2023-08-03 15:45:08 INFO    :    4   4.42928061e+05 -6.80280665e+06  3.28e+04 2.66e-01  1.41e+02   485s
2023-08-03 15:45:15 INFO    :    5   8.45902059e+04 -2.86621004e+06  3.47e+03 8.92e-01  2.26e+01   492s
2023-08-03 15:45:15 INFO    : 
2023-08-03 15:45:15 INFO    : Barrier performed 5 iterations in 492.31 seconds (433.74 work units)
2023-08-03 15:45:15 INFO    : Barrier solve interrupted - model solved by another algorithm
2023-08-03 15:45:15 INFO    : 
2023-08-03 15:45:15 INFO    : Concurrent spin time: 0.61s
2023-08-03 15:45:15 INFO    : 
2023-08-03 15:45:15 INFO    : Solved with dual simplex
2023-08-03 15:45:15 INFO    : 
2023-08-03 15:45:15 INFO    : Root relaxation: objective 2.099712e+04, 51942 iterations, 74.62 seconds (101.22 work units)
2023-08-03 15:45:18 INFO    : Total elapsed time = 495.24s
2023-08-03 15:45:21 INFO    : 
2023-08-03 15:45:21 INFO    :     Nodes    |    Current Node    |     Objective Bounds      |     Work
2023-08-03 15:45:21 INFO    :  Expl Unexpl |  Obj  Depth IntInf | Incumbent    BestBd   Gap | It/Node Time
2023-08-03 15:45:21 INFO    : 
2023-08-03 15:45:21 INFO    :      0     0 20997.1172    0  925 29414.5409 20997.1172  28.6%     -  497s
2023-08-03 15:45:45 INFO    :      0     0 21666.2343    0 1962 29414.5409 21666.2343  26.3%     -  522s
2023-08-03 15:45:47 INFO    : H    0     0                    29414.160890 21666.2343  26.3%     -  523s
2023-08-03 15:45:47 INFO    :      0     0 21666.2343    0 1966 29414.1609 21666.2343  26.3%     -  523s
2023-08-03 15:48:24 INFO    :      0     0 27351.1590    0  959 29414.1609 27351.1590  7.01%     -  681s
2023-08-03 15:48:27 INFO    : H    0     0                    29412.690310 27351.1590  7.01%     -  683s
2023-08-03 15:49:04 INFO    :      0     0 27402.4135    0  884 29412.6903 27402.4135  6.83%     -  720s
2023-08-03 15:49:04 INFO    :      0     0 27402.4135    0  829 29412.6903 27402.4135  6.83%     -  721s
2023-08-03 15:49:12 INFO    :      0     0 27402.4189    0  908 29412.6903 27402.4189  6.83%     -  728s
2023-08-03 15:49:26 INFO    :      0     0 27403.9616    0 1234 29412.6903 27403.9616  6.83%     -  743s
2023-08-03 15:49:33 INFO    :      0     0 27404.0963    0 1364 29412.6903 27404.0963  6.83%     -  750s
2023-08-03 15:49:33 INFO    :      0     0 27404.1429    0 1341 29412.6903 27404.1429  6.83%     -  750s
2023-08-03 15:49:34 INFO    :      0     0 27404.1493    0 1350 29412.6903 27404.1493  6.83%     -  750s
2023-08-03 15:49:45 INFO    :      0     0 27406.0628    0 1361 29412.6903 27406.0628  6.82%     -  761s
2023-08-03 15:49:46 INFO    : H    0     0                    29412.405730 27406.0628  6.82%     -  763s
2023-08-03 15:49:52 INFO    :      0     0 27406.2387    0 1455 29412.4057 27406.2387  6.82%     -  769s
2023-08-03 15:49:54 INFO    :      0     0 27406.2616    0 1486 29412.4057 27406.2616  6.82%     -  770s
2023-08-03 15:49:54 INFO    :      0     0 27406.2636    0 1476 29412.4057 27406.2636  6.82%     -  771s
2023-08-03 15:50:12 INFO    :      0     0 27407.4604    0 1773 29412.4057 27407.4604  6.82%     -  788s
2023-08-03 15:50:17 INFO    :      0     0 27407.5813    0 1808 29412.4057 27407.5813  6.82%     -  793s
2023-08-03 15:50:18 INFO    :      0     0 27407.6141    0 1758 29412.4057 27407.6141  6.82%     -  794s
2023-08-03 15:50:18 INFO    :      0     0 27407.6244    0 1745 29412.4057 27407.6244  6.82%     -  795s
2023-08-03 15:50:19 INFO    :      0     0 27407.6248    0 1779 29412.4057 27407.6248  6.82%     -  795s
2023-08-03 15:50:33 INFO    :      0     0 27409.4687    0 1519 29412.4057 27409.4687  6.81%     -  809s
2023-08-03 15:50:37 INFO    :      0     0 27409.7326    0 1572 29412.4057 27409.7326  6.81%     -  813s
2023-08-03 15:50:38 INFO    :      0     0 27409.7413    0 1517 29412.4057 27409.7413  6.81%     -  814s
2023-08-03 15:50:39 INFO    :      0     0 27409.7440    0 1567 29412.4057 27409.7440  6.81%     -  815s
2023-08-03 15:50:50 INFO    :      0     0 27411.3504    0 1524 29412.4057 27411.3504  6.80%     -  826s
2023-08-03 15:50:55 INFO    :      0     0 27411.6036    0 1669 29412.4057 27411.6036  6.80%     -  832s
2023-08-03 15:50:58 INFO    :      0     0 27411.7127    0 1587 29412.4057 27411.7127  6.80%     -  834s
2023-08-03 15:50:58 INFO    :      0     0 27411.7144    0 1594 29412.4057 27411.7144  6.80%     -  835s
2023-08-03 15:51:13 INFO    :      0     0 27413.7370    0 1658 29412.4057 27413.7370  6.80%     -  849s
2023-08-03 15:51:20 INFO    :      0     0 27414.1487    0 1687 29412.4057 27414.1487  6.79%     -  856s
2023-08-03 15:51:21 INFO    :      0     0 27414.1592    0 1672 29412.4057 27414.1592  6.79%     -  857s
2023-08-03 15:51:22 INFO    :      0     0 27414.1601    0 1705 29412.4057 27414.1601  6.79%     -  858s
2023-08-03 15:51:37 INFO    :      0     0 27416.1886    0 1742 29412.4057 27416.1886  6.79%     -  873s
2023-08-03 15:51:41 INFO    :      0     0 27416.3744    0 1820 29412.4057 27416.3744  6.79%     -  877s
2023-08-03 15:51:42 INFO    :      0     0 27416.3892    0 1737 29412.4057 27416.3892  6.79%     -  878s
2023-08-03 15:51:42 INFO    :      0     0 27416.3899    0 1741 29412.4057 27416.3899  6.79%     -  879s
2023-08-03 15:51:53 INFO    :      0     0 27417.3368    0 1765 29412.4057 27417.3368  6.78%     -  890s
2023-08-03 15:51:57 INFO    :      0     0 27417.5002    0 1802 29412.4057 27417.5002  6.78%     -  893s
2023-08-03 15:51:59 INFO    :      0     0 27417.5280    0 1798 29412.4057 27417.5280  6.78%     -  895s
2023-08-03 15:52:00 INFO    :      0     0 27417.5306    0 1779 29412.4057 27417.5306  6.78%     -  896s
2023-08-03 15:52:07 INFO    :      0     0 27417.9163    0 1722 29412.4057 27417.9163  6.78%     -  904s
2023-08-03 15:52:11 INFO    :      0     0 27418.0006    0 1698 29412.4057 27418.0006  6.78%     -  907s
2023-08-03 15:52:12 INFO    :      0     0 27418.0077    0 1724 29412.4057 27418.0077  6.78%     -  908s
2023-08-03 15:52:21 INFO    :      0     0 27418.5766    0 1788 29412.4057 27418.5766  6.78%     -  917s
2023-08-03 15:52:24 INFO    :      0     0 27418.6285    0 1838 29412.4057 27418.6285  6.78%     -  920s
2023-08-03 15:52:25 INFO    :      0     0 27418.6531    0 1816 29412.4057 27418.6531  6.78%     -  921s
2023-08-03 15:52:25 INFO    :      0     0 27418.6565    0 1812 29412.4057 27418.6565  6.78%     -  922s
2023-08-03 15:52:33 INFO    :      0     0 27418.9580    0 1915 29412.4057 27418.9580  6.78%     -  930s
2023-08-03 15:52:36 INFO    :      0     0 27418.9793    0 2032 29412.4057 27418.9793  6.78%     -  932s
2023-08-03 15:52:37 INFO    :      0     0 27418.9908    0 2041 29412.4057 27418.9908  6.78%     -  933s
2023-08-03 15:52:38 INFO    :      0     0 27418.9976    0 2028 29412.4057 27418.9976  6.78%     -  934s
2023-08-03 15:52:43 INFO    :      0     0 27419.2604    0 1787 29412.4057 27419.2604  6.78%     -  940s
2023-08-03 15:52:46 INFO    :      0     0 27419.2640    0 1861 29412.4057 27419.2640  6.78%     -  943s
2023-08-03 15:52:50 INFO    :      0     0 27419.3072    0 1864 29412.4057 27419.3072  6.78%     -  947s
2023-08-03 15:52:52 INFO    :      0     0 27419.3177    0 1845 29412.4057 27419.3177  6.78%     -  949s
2023-08-03 15:52:57 INFO    :      0     0 27419.4361    0 1823 29412.4057 27419.4361  6.78%     -  954s
2023-08-03 15:53:02 INFO    :      0     0 27419.4520    0 2012 29412.4057 27419.4520  6.78%     -  958s
2023-08-03 15:53:03 INFO    :      0     0 27419.4530    0 1865 29412.4057 27419.4530  6.78%     -  960s
2023-08-03 15:53:08 INFO    :      0     0 27419.5067    0 1862 29412.4057 27419.5067  6.78%     -  965s
2023-08-03 15:53:11 INFO    :      0     0 27419.5543    0 1918 29412.4057 27419.5543  6.78%     -  967s
2023-08-03 15:53:17 INFO    :      0     0 27419.5595    0 1924 29412.4057 27419.5595  6.78%     -  974s
2023-08-03 15:53:21 INFO    :      0     0 27419.6889    0 1939 29412.4057 27419.6889  6.78%     -  978s
2023-08-03 15:53:22 INFO    : H    0     0                    29412.026530 27419.6889  6.77%     -  978s
2023-08-03 15:53:23 INFO    :      0     0 27419.6906    0 1934 29412.0265 27419.6906  6.77%     -  979s
2023-08-03 15:53:29 INFO    :      0     0 27419.7799    0 1966 29412.0265 27419.7799  6.77%     -  986s
2023-08-03 15:53:32 INFO    :      0     0 27419.8205    0 1927 29412.0265 27419.8205  6.77%     -  989s
2023-08-03 15:53:33 INFO    :      0     0 27419.8335    0 1938 29412.0265 27419.8335  6.77%     -  990s
2023-08-03 15:53:38 INFO    :      0     0 27419.8339    0 1872 29412.0265 27419.8339  6.77%     -  995s
2023-08-03 15:53:43 INFO    :      0     0 27419.9216    0 1817 29412.0265 27419.9216  6.77%     - 1000s
2023-08-03 15:53:45 INFO    :      0     0 27419.9242    0 1853 29412.0265 27419.9242  6.77%     - 1001s
2023-08-03 15:53:47 INFO    :      0     0 27420.0410    0 1853 29412.0265 27420.0410  6.77%     - 1004s
2023-08-03 15:53:49 INFO    :      0     0 27420.0497    0 1840 29412.0265 27420.0497  6.77%     - 1005s
2023-08-03 15:53:52 INFO    :      0     0 27420.1076    0 1853 29412.0265 27420.1076  6.77%     - 1009s
2023-08-03 15:53:53 INFO    : H    0     0                    29411.883730 27420.1076  6.77%     - 1009s
2023-08-03 15:53:54 INFO    :      0     0 27420.1102    0 1829 29411.8837 27420.1102  6.77%     - 1010s
2023-08-03 15:54:01 INFO    :      0     0 27420.1138    0 1836 29411.8837 27420.1138  6.77%     - 1017s
2023-08-03 15:54:02 INFO    :      0     0 27420.1138    0 1836 29411.8837 27420.1138  6.77%     - 1018s
2023-08-03 15:54:24 INFO    :      0     2 27420.1138    0 1836 29411.8837 27420.1138  6.77%     - 1041s
2023-08-03 15:54:30 INFO    :      3     8 27420.1143    2 1865 29411.8837 27420.1138  6.77%  1339 1046s
2023-08-03 15:54:44 INFO    :      7    16 27420.1146    3 1911 29411.8837 27420.1143  6.77%  1614 1061s
2023-08-03 15:55:01 INFO    :     15    24 27420.1147    4 1926 29411.8837 27420.1146  6.77%  2695 1077s
2023-08-03 15:55:23 INFO    :     23    32 27420.1148    4 1942 29411.8837 27420.1148  6.77%  3298 1100s
2023-08-03 15:55:54 INFO    :     31    40 27420.1782    5 1668 29411.8837 27420.1211  6.77%  4465 1130s
2023-08-03 15:56:11 INFO    :     39    48 28417.4807    5 1936 29411.8837 27420.1211  6.77%  4703 1147s
2023-08-03 15:56:20 INFO    :     47    61 27420.1881    6 1660 29411.8837 27420.1211  6.77%  4346 1156s
2023-08-03 15:56:39 INFO    :     60    76 27420.1944    8 1682 29411.8837 27420.1211  6.77%  3750 1175s
2023-08-03 15:57:02 INFO    :     75    87 27420.3122   10 1656 29411.8837 27420.1211  6.77%  3400 1199s
2023-08-03 15:57:49 INFO    :     86   112 27420.5534   12 1785 29411.8837 27420.1211  6.77%  3241 1246s
2023-08-03 15:58:39 INFO    :    111   210 27420.4548   15 1628 29411.8837 27420.1211  6.77%  3388 1295s
2023-08-03 16:00:29 INFO    :    209   453 27420.4867   23 1619 29411.8837 27420.1211  6.77%  2284 1405s
2023-08-03 16:03:29 INFO    :    454   945 27421.2360   40 1654 29411.8837 27420.1211  6.77%  1621 1585s
2023-08-03 16:07:00 INFO    :    946  1500 27421.8860   54 1676 29411.8837 27420.1211  6.77%  1127 1797s
2023-08-03 16:07:03 INFO    :   1524  1505 27423.4253   93 1470 29411.8837 27420.1211  6.77%  1057 1800s
2023-08-03 16:07:03 INFO    : 
2023-08-03 16:07:03 INFO    : Cutting planes:
2023-08-03 16:07:03 INFO    :   Learned: 2
2023-08-03 16:07:03 INFO    :   Gomory: 15
2023-08-03 16:07:03 INFO    :   Cover: 18
2023-08-03 16:07:03 INFO    :   Implied bound: 637
2023-08-03 16:07:03 INFO    :   Clique: 165
2023-08-03 16:07:03 INFO    :   MIR: 1640
2023-08-03 16:07:03 INFO    :   StrongCG: 5
2023-08-03 16:07:03 INFO    :   Flow cover: 876
2023-08-03 16:07:03 INFO    :   Zero half: 13
2023-08-03 16:07:03 INFO    :   RLT: 160
2023-08-03 16:07:03 INFO    :   Relax-and-lift: 555
2023-08-03 16:07:04 INFO    : 
2023-08-03 16:07:04 INFO    : Explored 1529 nodes (2028067 simplex iterations) in 1800.66 seconds (3670.33 work units)
2023-08-03 16:07:04 INFO    : Thread count was 16 (of 16 available processors)
2023-08-03 16:07:04 INFO    : 
2023-08-03 16:07:04 INFO    : Solution count 10: 29411.9 29412 29412.4 ... 29441.1

In the last ~800 seconds, there was no (real) improvement in the solution. So to me it seems like Gurobi is having a hard time to converge at this time? It also starts searching outside the root node. How could I improve this? Can I do more to let Gurobi converge faster?

MILP model 09:

2023-08-03 16:24:29 INFO    :     Nodes    |    Current Node    |     Objective Bounds      |     Work
2023-08-03 16:24:29 INFO    :  Expl Unexpl |  Obj  Depth IntInf | Incumbent    BestBd   Gap | It/Node Time
2023-08-03 16:24:29 INFO    : 
2023-08-03 16:24:29 INFO    :      0     0 30153.2006    0 1227 35664.0903 30153.2006  15.5%     -  678s
2023-08-03 16:24:43 INFO    :      0     0 30353.8793    0 1404 35664.0903 30353.8793  14.9%     -  693s
2023-08-03 16:24:46 INFO    :      0     0 30422.0283    0 1207 35664.0903 30422.0283  14.7%     -  696s
2023-08-03 16:24:48 INFO    :      0     0 30422.0283    0 1154 35664.0903 30422.0283  14.7%     -  698s
2023-08-03 16:40:21 INFO    :      0     0 32533.3574    0 1209 35664.0903 32533.3574  8.78%     - 1630s
2023-08-03 16:40:24 INFO    : H    0     0                    35664.010250 32533.3574  8.78%     - 1634s
2023-08-03 16:42:16 INFO    :      0     0 32543.4170    0 1468 35664.0103 32543.4170  8.75%     - 1746s
2023-08-03 16:42:47 INFO    :      0     0 32562.0237    0 1429 35664.0103 32562.0237  8.70%     - 1776s
2023-08-03 16:43:10 INFO    :      0     0          -    0      35664.0103 32562.0237  8.70%     - 1800s

It takes ~1000 seconds to get from 14.7% to 8.78%. How can this be explained? Why does this one iteration step take so long? Can an improvement be made on this?

MILP model 10:

2023-08-03 16:52:11 INFO    : Academic license - for non-commercial use only - registered to XX
2023-08-03 16:52:11 INFO    : Optimize a model with 2430299 rows, 902595 columns and 13352943 nonzeros
2023-08-03 16:52:11 INFO    : Model fingerprint: 0x3e4fe57f
2023-08-03 16:52:11 INFO    : Variable types: 20477 continuous, 882118 integer (882118 binary)
2023-08-03 16:52:11 INFO    : Coefficient statistics:
2023-08-03 16:52:11 INFO    :   Matrix range     [2e-01, 1e+03]
2023-08-03 16:52:11 INFO    :   Objective range  [1e-03, 5e+02]
2023-08-03 16:52:11 INFO    :   Bounds range     [1e-13, 1e+03]
2023-08-03 16:52:11 INFO    :   RHS range        [1e+00, 3e+03]

The Bounds range is very big. As explained above, I would like to fix this, but I don't exactly know how...

2023-08-03 17:03:08 INFO    : Deterministic concurrent LP optimizer: primal simplex, dual simplex, and barrier
2023-08-03 17:03:08 INFO    : Showing barrier log only...
2023-08-03 17:03:08 INFO    : 
2023-08-03 17:03:09 INFO    : Root barrier log...
2023-08-03 17:03:09 INFO    : 
2023-08-03 17:03:16 INFO    : Elapsed ordering time = 5s
2023-08-03 17:03:21 INFO    : Elapsed ordering time = 10s
2023-08-03 17:03:26 INFO    : Elapsed ordering time = 15s
2023-08-03 17:03:31 INFO    : Elapsed ordering time = 20s
2023-08-03 17:03:36 INFO    : Elapsed ordering time = 25s
2023-08-03 17:04:50 INFO    : Ordering time: 98.76s
2023-08-03 17:04:52 INFO    : Elapsed ordering time = 99s
2023-08-03 17:04:53 INFO    : Elapsed ordering time = 100s
2023-08-03 17:04:58 INFO    : Elapsed ordering time = 105s
2023-08-03 17:05:03 INFO    : Elapsed ordering time = 110s
2023-08-03 17:05:08 INFO    : Elapsed ordering time = 115s
2023-08-03 17:05:13 INFO    : Elapsed ordering time = 120s
2023-08-03 17:05:20 INFO    : Elapsed ordering time = 127s
2023-08-03 17:05:23 INFO    : Elapsed ordering time = 130s
2023-08-03 17:05:28 INFO    : Elapsed ordering time = 135s
2023-08-03 17:05:33 INFO    : Elapsed ordering time = 140s
2023-08-03 17:05:38 INFO    : Elapsed ordering time = 145s
2023-08-03 17:05:43 INFO    : Elapsed ordering time = 150s
2023-08-03 17:05:48 INFO    : Elapsed ordering time = 155s
2023-08-03 17:05:53 INFO    : Elapsed ordering time = 160s
2023-08-03 17:05:58 INFO    : Elapsed ordering time = 165s
2023-08-03 17:06:03 INFO    : Elapsed ordering time = 170s
2023-08-03 17:06:08 INFO    : Elapsed ordering time = 175s
2023-08-03 17:06:13 INFO    : Elapsed ordering time = 180s
2023-08-03 17:06:18 INFO    : Elapsed ordering time = 185s
2023-08-03 17:06:23 INFO    : Elapsed ordering time = 190s
2023-08-03 17:06:28 INFO    : Elapsed ordering time = 195s
2023-08-03 17:06:33 INFO    : Elapsed ordering time = 200s
2023-08-03 17:06:38 INFO    : Elapsed ordering time = 205s
2023-08-03 17:06:43 INFO    : Elapsed ordering time = 210s
2023-08-03 17:06:48 INFO    : Elapsed ordering time = 215s
2023-08-03 17:06:51 INFO    : Ordering time: 217.58s
2023-08-03 17:07:00 INFO    : 
2023-08-03 17:07:00 INFO    : Barrier statistics:
2023-08-03 17:07:00 INFO    :  Dense cols : 359
2023-08-03 17:07:00 INFO    :  AA' NZ     : 4.021e+07
2023-08-03 17:07:00 INFO    :  Factor NZ  : 1.119e+09 (roughly 10.0 GB of memory)
2023-08-03 17:07:00 INFO    :  Factor Ops : 4.810e+12 (roughly 25 seconds per iteration)
2023-08-03 17:07:00 INFO    :  Threads    : 6
2023-08-03 17:07:14 INFO    : 
2023-08-03 17:07:14 INFO    :                   Objective                Residual
2023-08-03 17:07:14 INFO    : Iter       Primal          Dual         Primal    Dual     Compl     Time
2023-08-03 17:07:15 INFO    :    0   1.91842913e+07 -5.53869499e+07  3.15e+05 9.23e-01  1.95e+03   903s
2023-08-03 17:07:29 INFO    :    1   1.16660794e+07 -6.11275768e+07  1.89e+05 3.34e+00  1.14e+03   918s
2023-08-03 17:07:45 INFO    :    2   3.27761765e+06 -5.29292803e+07  5.26e+04 1.70e-01  3.37e+02   933s
2023-08-03 17:07:51 INFO    : 
2023-08-03 17:07:51 INFO    : Barrier performed 2 iterations in 939.87 seconds (828.02 work units)
2023-08-03 17:07:51 INFO    : Barrier solve interrupted - model solved by another algorithm

What about the 200+ seconds ordering time? What can I do to improve this?

MILP model 11:

2023-08-03 17:30:38 INFO    : Academic license - for non-commercial use only - registered to XX
2023-08-03 17:30:38 INFO    : Optimize a model with 2181829 rows, 833759 columns and 11979891 nonzeros
2023-08-03 17:30:38 INFO    : Model fingerprint: 0x14a217ab
2023-08-03 17:30:38 INFO    : Variable types: 20072 continuous, 813687 integer (813687 binary)
2023-08-03 17:30:38 INFO    : Coefficient statistics:
2023-08-03 17:30:38 INFO    :   Matrix range     [2e-01, 1e+03]
2023-08-03 17:30:38 INFO    :   Objective range  [1e-03, 5e+02]
2023-08-03 17:30:38 INFO    :   Bounds range     [6e-14, 1e+03]
2023-08-03 17:30:38 INFO    :   RHS range        [1e+00, 3e+03]
...
2023-08-03 17:42:02 INFO    : Deterministic concurrent LP optimizer: primal simplex, dual simplex, and barrier
2023-08-03 17:42:02 INFO    : Showing barrier log only...
2023-08-03 17:42:02 INFO    : 
2023-08-03 17:42:04 INFO    : Root barrier log...
2023-08-03 17:42:04 INFO    : 
2023-08-03 17:42:11 INFO    : Elapsed ordering time = 5s
2023-08-03 17:42:16 INFO    : Elapsed ordering time = 10s
2023-08-03 17:42:21 INFO    : Elapsed ordering time = 15s
2023-08-03 17:42:26 INFO    : Elapsed ordering time = 20s
2023-08-03 17:42:31 INFO    : Elapsed ordering time = 25s
2023-08-03 17:42:36 INFO    : Elapsed ordering time = 30s
2023-08-03 17:42:41 INFO    : Elapsed ordering time = 35s
2023-08-03 17:42:46 INFO    : Elapsed ordering time = 40s
2023-08-03 17:44:36 INFO    : Ordering time: 150.07s
2023-08-03 17:44:39 INFO    : Elapsed ordering time = 150s
2023-08-03 17:44:44 INFO    : Elapsed ordering time = 155s
2023-08-03 17:44:49 INFO    : Elapsed ordering time = 160s
2023-08-03 17:44:54 INFO    : Elapsed ordering time = 165s
2023-08-03 17:44:59 INFO    : Elapsed ordering time = 170s
2023-08-03 17:45:04 INFO    : Elapsed ordering time = 175s
2023-08-03 17:45:09 INFO    : Elapsed ordering time = 180s
2023-08-03 17:45:14 INFO    : Elapsed ordering time = 185s
2023-08-03 17:45:21 INFO    : Elapsed ordering time = 192s
2023-08-03 17:45:24 INFO    : Elapsed ordering time = 195s
2023-08-03 17:45:29 INFO    : Elapsed ordering time = 200s
2023-08-03 17:45:34 INFO    : Elapsed ordering time = 205s
2023-08-03 17:45:39 INFO    : Elapsed ordering time = 210s
2023-08-03 17:45:44 INFO    : Elapsed ordering time = 215s
2023-08-03 17:45:49 INFO    : Elapsed ordering time = 220s
2023-08-03 17:45:54 INFO    : Elapsed ordering time = 225s
2023-08-03 17:45:59 INFO    : Elapsed ordering time = 230s
2023-08-03 17:46:04 INFO    : Elapsed ordering time = 235s
2023-08-03 17:46:09 INFO    : Elapsed ordering time = 240s
2023-08-03 17:46:14 INFO    : Elapsed ordering time = 245s
2023-08-03 17:46:19 INFO    : Elapsed ordering time = 250s
2023-08-03 17:46:24 INFO    : Elapsed ordering time = 255s
2023-08-03 17:46:29 INFO    : Elapsed ordering time = 260s
2023-08-03 17:46:34 INFO    : Elapsed ordering time = 265s
2023-08-03 17:46:39 INFO    : Elapsed ordering time = 270s
2023-08-03 17:46:44 INFO    : Elapsed ordering time = 275s
2023-08-03 17:46:49 INFO    : Elapsed ordering time = 280s
2023-08-03 17:46:54 INFO    : Elapsed ordering time = 285s
2023-08-03 17:46:59 INFO    : Elapsed ordering time = 290s
2023-08-03 17:47:04 INFO    : Elapsed ordering time = 295s
2023-08-03 17:47:09 INFO    : Elapsed ordering time = 300s
2023-08-03 17:47:14 INFO    : Elapsed ordering time = 305s
2023-08-03 17:47:21 INFO    : Ordering time: 311.89s

The same problems can be found in model 11. Next to that, there is actually no progress in the MIP solving phase:

2023-08-03 17:50:34 INFO    : Root relaxation: objective 3.212075e+04, 182675 iterations, 512.57 seconds (691.80 work units)
2023-08-03 17:50:48 INFO    : 
2023-08-03 17:50:48 INFO    :     Nodes    |    Current Node    |     Objective Bounds      |     Work
2023-08-03 17:50:48 INFO    :  Expl Unexpl |  Obj  Depth IntInf | Incumbent    BestBd   Gap | It/Node Time
2023-08-03 17:50:48 INFO    : 
2023-08-03 17:50:48 INFO    :      0     0 32120.7468    0 1790 55283.4966 32120.7468  41.9%     - 1210s
2023-08-03 17:51:15 INFO    :      0     0 32122.4707    0 1885 55283.4966 32122.4707  41.9%     - 1237s
2023-08-03 17:51:27 INFO    :      0     0 32122.4707    0 1801 55283.4966 32122.4707  41.9%     - 1249s
2023-08-03 18:00:40 INFO    : 
2023-08-03 18:00:40 INFO    : Explored 1 nodes (197028 simplex iterations) in 1802.48 seconds (2082.61 work units)
2023-08-03 18:00:40 INFO    : Thread count was 16 (of 16 available processors)
2023-08-03 18:00:40 INFO    : 
2023-08-03 18:00:40 INFO    : Solution count 10: 55283.5 55286.8 55286.8 ... 55825.9

MILP model 13:

This log is an example that sometimes everything seems to work fine though:

2023-08-03 18:41:53 INFO    : Set parameter NoRelHeurTime to value 440
2023-08-03 18:41:53 INFO    : Set parameter IntegralityFocus to value 1
2023-08-03 18:41:53 INFO    : Set parameter LogFile to value "Gurobi_log_13"
2023-08-03 18:41:53 INFO    : Set parameter MIPGapAbs to value 0.05
2023-08-03 18:41:53 INFO    : Set parameter TimeLimit to value 1800
2023-08-03 18:41:53 INFO    : Gurobi Optimizer version 10.0.1 build v10.0.1rc0 (win64)
2023-08-03 18:41:53 INFO    : 
2023-08-03 18:41:53 INFO    : CPU model: 11th Gen Intel(R) Core(TM) i7-11700 @ 2.50GHz, instruction set [SSE2|AVX|AVX2|AVX512]
2023-08-03 18:41:53 INFO    : Thread count: 8 physical cores, 16 logical processors, using up to 16 threads
2023-08-03 18:41:53 INFO    : 
2023-08-03 18:41:53 INFO    : Academic license - for non-commercial use only - registered to XXX
2023-08-03 18:41:53 INFO    : Optimize a model with 1496775 rows, 506383 columns and 7430779 nonzeros
2023-08-03 18:41:53 INFO    : Model fingerprint: 0x196c429f
2023-08-03 18:41:53 INFO    : Variable types: 16349 continuous, 490034 integer (490034 binary)
2023-08-03 18:41:53 INFO    : Coefficient statistics:
2023-08-03 18:41:53 INFO    :   Matrix range     [2e-01, 1e+03]
2023-08-03 18:41:53 INFO    :   Objective range  [1e-03, 5e+02]
2023-08-03 18:41:53 INFO    :   Bounds range     [1e-01, 1e+03]
2023-08-03 18:41:53 INFO    :   RHS range        [1e+00, 3e+03]
2023-08-03 18:41:53 INFO    : 
2023-08-03 18:41:53 INFO    : Warning: Completing partial solution with 489835 unfixed non-continuous variables out of 490034
2023-08-03 18:41:56 INFO    : User MIP start produced solution with objective 53000.4 (2.25s)
2023-08-03 18:41:56 INFO    : User MIP start produced solution with objective 53000.4 (2.29s)
2023-08-03 18:41:56 INFO    : Loaded user MIP start with objective 53000.4
2023-08-03 18:41:56 INFO    : Processed MIP start in 2.29 seconds (3.21 work units)
2023-08-03 18:41:56 INFO    : 
2023-08-03 18:42:01 INFO    : Presolve removed 1252102 rows and 424954 columns (presolve time = 5s) ...
2023-08-03 18:42:06 INFO    : Presolve removed 1297650 rows and 431703 columns (presolve time = 10s) ...
2023-08-03 18:42:11 INFO    : Presolve removed 1360709 rows and 449401 columns (presolve time = 15s) ...
2023-08-03 18:42:16 INFO    : Presolve removed 1370415 rows and 453047 columns (presolve time = 20s) ...
2023-08-03 18:42:21 INFO    : Presolve removed 1373597 rows and 455471 columns (presolve time = 25s) ...
2023-08-03 18:42:26 INFO    : Presolve removed 1375164 rows and 456181 columns (presolve time = 30s) ...
2023-08-03 18:42:26 INFO    : Presolve removed 1375007 rows and 456024 columns
2023-08-03 18:42:26 INFO    : Presolve time: 30.33s
2023-08-03 18:42:26 INFO    : Presolved: 121768 rows, 50359 columns, 992696 nonzeros
2023-08-03 18:42:27 INFO    : Variable types: 4608 continuous, 45751 integer (45747 binary)
2023-08-03 18:42:27 INFO    : Starting NoRel heuristic
2023-08-03 18:42:30 INFO    : Found heuristic solution: objective 53000.058000
...
2023-08-03 18:49:47 INFO    : Elapsed time for NoRel heuristic: 440s (best bound 38506.9)
2023-08-03 18:49:47 INFO    : 
2023-08-03 18:49:47 INFO    : Deterministic concurrent LP optimizer: primal simplex, dual simplex, and barrier
2023-08-03 18:49:47 INFO    : Showing barrier log only...
2023-08-03 18:49:47 INFO    : 
2023-08-03 18:49:47 INFO    : Root barrier log...
2023-08-03 18:49:47 INFO    : 
2023-08-03 18:49:53 INFO    : Ordering time: 5.68s
2023-08-03 18:49:54 INFO    : Elapsed ordering time = 6s
2023-08-03 18:49:58 INFO    : Elapsed ordering time = 10s
2023-08-03 18:50:00 INFO    : Ordering time: 11.60s
2023-08-03 18:50:00 INFO    : 
2023-08-03 18:50:00 INFO    : Barrier statistics:
2023-08-03 18:50:00 INFO    :  Dense cols : 1038
2023-08-03 18:50:00 INFO    :  AA' NZ     : 7.850e+06
2023-08-03 18:50:00 INFO    :  Factor NZ  : 7.401e+07 (roughly 700 MB of memory)
2023-08-03 18:50:00 INFO    :  Factor Ops : 1.095e+11 (roughly 1 second per iteration)
2023-08-03 18:50:00 INFO    :  Threads    : 6
2023-08-03 18:50:01 INFO    : 
2023-08-03 18:50:01 INFO    :                   Objective                Residual
2023-08-03 18:50:01 INFO    : Iter       Primal          Dual         Primal    Dual     Compl     Time
2023-08-03 18:50:01 INFO    :    0   1.03489346e+09 -1.87939174e+08  1.12e+07 1.01e+02  7.53e+06   487s
2023-08-03 18:50:01 INFO    :    1   1.03489363e+09 -1.87967573e+08  1.12e+07 1.32e+03  7.53e+06   488s
2023-08-03 18:50:02 INFO    :    2   7.66982213e+08 -3.05642891e+08  8.14e+06 8.35e+02  6.12e+06   489s
2023-08-03 18:50:04 INFO    :    3   4.74890903e+08 -3.89496915e+08  5.04e+06 3.59e+02  3.72e+06   490s
2023-08-03 18:50:05 INFO    :    4   2.19519247e+08 -4.77297341e+08  2.34e+06 3.77e+01  1.72e+06   491s
2023-08-03 18:50:06 INFO    :    5   7.54082438e+07 -5.18395432e+08  8.01e+05 3.72e-02  6.24e+05   492s
2023-08-03 18:50:07 INFO    :    6   7.43384490e+05 -5.02881321e+08  7.38e+03 2.05e+00  8.04e+03   493s
2023-08-03 18:50:08 INFO    :    7   2.24692745e+05 -1.96629413e+08  1.89e+03 1.40e-01  2.09e+03   495s
2023-08-03 18:50:09 INFO    :    8   8.28208077e+04 -6.40830972e+07  3.84e+02 2.51e-02  4.87e+02   496s
2023-08-03 18:50:11 INFO    :    9   5.64936087e+04 -1.59070583e+07  7.28e+01 3.66e-03  1.01e+02   497s
2023-08-03 18:50:12 INFO    :   10   5.29148440e+04 -5.53152566e+06  2.00e+01 3.13e-03  3.09e+01   498s
2023-08-03 18:50:13 INFO    :   11   5.01444684e+04 -1.17814595e+06  2.15e-01 1.17e-03  5.75e+00   499s
2023-08-03 18:50:14 INFO    :   12   4.82670404e+04 -2.95430314e+05  7.04e-02 3.47e-04  1.61e+00   500s
2023-08-03 18:50:15 INFO    :   13   4.70067798e+04 -1.70291643e+05  4.72e-02 2.29e-04  1.01e+00   501s
2023-08-03 18:50:16 INFO    :   14   4.46377226e+04 -4.94123295e+04  1.82e-02 1.92e-04  4.39e-01   502s
2023-08-03 18:50:17 INFO    :   15   4.34129262e+04 -1.20288783e+04  1.06e-02 8.34e-05  2.59e-01   503s
2023-08-03 18:50:18 INFO    :   16   4.23756925e+04 -3.04939406e+03  7.43e-03 8.48e-05  2.12e-01   504s
2023-08-03 18:50:19 INFO    :   17   4.17356301e+04  8.67365549e+03  5.96e-03 5.26e-05  1.54e-01   505s
2023-08-03 18:50:20 INFO    :   18   4.14374523e+04  1.66469850e+04  4.85e-03 7.21e-05  1.16e-01   506s
2023-08-03 18:50:21 INFO    :   19   4.03005231e+04  3.00550153e+04  1.56e-03 1.13e-04  4.78e-02   507s
2023-08-03 18:50:22 INFO    :   20   3.97899677e+04  3.35864423e+04  4.96e-04 7.22e-05  2.89e-02   508s
2023-08-03 18:50:23 INFO    :   21   3.94678526e+04  3.55733348e+04  2.69e-04 4.82e-05  1.82e-02   510s
2023-08-03 18:50:24 INFO    :   22   3.92075746e+04  3.64717070e+04  1.67e-04 3.58e-05  1.28e-02   511s
2023-08-03 18:50:25 INFO    :   23   3.90019235e+04  3.75004439e+04  1.10e-04 1.87e-05  7.01e-03   512s
2023-08-03 18:50:26 INFO    :   24   3.89233503e+04  3.78438319e+04  8.69e-05 2.15e-05  5.04e-03   513s
2023-08-03 18:50:27 INFO    :   25   3.88538781e+04  3.80377482e+04  6.53e-05 1.88e-05  3.81e-03   514s
2023-08-03 18:50:28 INFO    :   26   3.87957321e+04  3.83667833e+04  4.64e-05 1.47e-05  2.00e-03   515s
2023-08-03 18:50:29 INFO    :   27   3.87306476e+04  3.84421814e+04  2.41e-05 1.06e-05  1.35e-03   516s
2023-08-03 18:50:30 INFO    :   28   3.86975658e+04  3.85618110e+04  1.29e-05 4.33e-06  6.33e-04   517s
2023-08-03 18:50:32 INFO    :   29   3.86789454e+04  3.85941550e+04  8.28e-06 2.69e-06  3.96e-04   518s
2023-08-03 18:50:33 INFO    :   30   3.86696515e+04  3.86148582e+04  5.85e-06 1.64e-06  2.56e-04   519s
2023-08-03 18:50:34 INFO    :   31   3.86572735e+04  3.86336724e+04  2.33e-06 6.93e-07  1.10e-04   521s
2023-08-03 18:50:35 INFO    :   32   3.86527196e+04  3.86414709e+04  1.25e-06 2.84e-07  5.25e-05   522s
2023-08-03 18:50:36 INFO    :   33   3.86511684e+04  3.86443164e+04  8.93e-07 2.43e-07  3.20e-05   523s
2023-08-03 18:50:38 INFO    :   34   3.86486899e+04  3.86457187e+04  3.33e-07 5.24e-07  1.39e-05   524s
2023-08-03 18:50:40 INFO    :   35   3.86483731e+04  3.86459517e+04  2.78e-07 4.57e-07  1.13e-05   526s
2023-08-03 18:50:41 INFO    :   36   3.86474880e+04  3.86469271e+04  7.25e-08 3.13e-07  2.62e-06   527s
2023-08-03 18:50:42 INFO    :   37   3.86474880e+04  3.86469273e+04  7.25e-08 6.98e-06  2.62e-06   528s
2023-08-03 18:50:43 INFO    :   38   3.86473806e+04  3.86470310e+04  4.71e-08 1.90e-06  1.63e-06   529s
2023-08-03 18:50:43 INFO    :   39   3.86473776e+04  3.86470361e+04  4.64e-08 6.57e-06  1.60e-06   530s
2023-08-03 18:50:43 INFO    : 
2023-08-03 18:50:43 INFO    : Barrier performed 39 iterations in 529.98 seconds (488.62 work units)
2023-08-03 18:50:43 INFO    : Barrier solve interrupted - model solved by another algorithm
2023-08-03 18:50:43 INFO    : 
2023-08-03 18:50:43 INFO    : Concurrent spin time: 3.73s
2023-08-03 18:50:43 INFO    : 
2023-08-03 18:50:43 INFO    : Solved with dual simplex
2023-08-03 18:50:43 INFO    : 
2023-08-03 18:50:43 INFO    : Root relaxation: objective 3.864716e+04, 62380 iterations, 56.83 seconds (73.43 work units)
2023-08-03 18:50:49 INFO    : Total elapsed time = 535.93s
2023-08-03 18:50:51 INFO    : 
2023-08-03 18:50:51 INFO    :     Nodes    |    Current Node    |     Objective Bounds      |     Work
2023-08-03 18:50:51 INFO    :  Expl Unexpl |  Obj  Depth IntInf | Incumbent    BestBd   Gap | It/Node Time
2023-08-03 18:50:51 INFO    : 
2023-08-03 18:50:51 INFO    :      0     0 38647.1622    0 1045 46633.6630 38647.1622  17.1%     -  537s
2023-08-03 18:50:53 INFO    :      0     0 38647.3935    0  942 46633.6630 38647.3935  17.1%     -  539s
2023-08-03 18:50:55 INFO    :      0     0 38647.4642    0  950 46633.6630 38647.4642  17.1%     -  541s
2023-08-03 18:50:55 INFO    :      0     0 38647.4642    0  950 46633.6630 38647.4642  17.1%     -  541s
2023-08-03 18:51:43 INFO    :      0     0 42666.3409    0 1008 46633.6630 42666.3409  8.51%     -  589s
2023-08-03 18:51:47 INFO    :      0     0 44031.2855    0 1055 46633.6630 44031.2855  5.58%     -  593s
2023-08-03 18:51:49 INFO    :      0     0 44483.1855    0 1016 46633.6630 44483.1855  4.61%     -  595s
2023-08-03 18:51:50 INFO    :      0     0 45003.1605    0  981 46633.6630 45003.1605  3.50%     -  596s
2023-08-03 18:51:57 INFO    :      0     0 45004.9037    0 1044 46633.6630 45004.9037  3.49%     -  603s
2023-08-03 18:52:04 INFO    :      0     0 45005.5270    0  965 46633.6630 45005.5270  3.49%     -  610s
2023-08-03 18:52:04 INFO    :      0     0 45005.5270    0  931 46633.6630 45005.5270  3.49%     -  610s
2023-08-03 18:52:10 INFO    :      0     0 45009.3630    0 1053 46633.6630 45009.3630  3.48%     -  616s
2023-08-03 18:52:17 INFO    :      0     0 45009.5796    0  931 46633.6630 45009.5796  3.48%     -  623s
2023-08-03 18:52:18 INFO    :      0     0 45009.5796    0  977 46633.6630 45009.5796  3.48%     -  624s
2023-08-03 18:52:25 INFO    :      0     0 45011.0113    0 1187 46633.6630 45011.0113  3.48%     -  631s
2023-08-03 18:52:26 INFO    :      0     0 45573.6276    0 1121 46633.6630 45573.6276  2.27%     -  632s
2023-08-03 18:52:31 INFO    :      0     0 45573.7196    0 1127 46633.6630 45573.7196  2.27%     -  637s
2023-08-03 18:52:32 INFO    :      0     0 45573.7482    0 1125 46633.6630 45573.7482  2.27%     -  638s
2023-08-03 18:52:37 INFO    :      0     0 45576.8785    0 1108 46633.6630 45576.8785  2.27%     -  643s
2023-08-03 18:52:39 INFO    :      0     0 45577.5082    0 1135 46633.6630 45577.5082  2.26%     -  645s
2023-08-03 18:52:40 INFO    :      0     0 45577.5659    0 1124 46633.6630 45577.5659  2.26%     -  646s
2023-08-03 18:52:43 INFO    :      0     0 45583.5671    0 1147 46633.6630 45583.5671  2.25%     -  649s
2023-08-03 18:52:46 INFO    :      0     0 45584.1972    0 1190 46633.6630 45584.1972  2.25%     -  652s
2023-08-03 18:52:47 INFO    :      0     0 45584.2558    0 1172 46633.6630 45584.2558  2.25%     -  653s
2023-08-03 18:52:50 INFO    :      0     0 45586.7403    0 1253 46633.6630 45586.7403  2.24%     -  656s
2023-08-03 18:52:52 INFO    :      0     0 45586.9749    0 1260 46633.6630 45586.9749  2.24%     -  658s
2023-08-03 18:52:53 INFO    :      0     0 45587.0888    0 1264 46633.6630 45587.0888  2.24%     -  659s
2023-08-03 18:52:53 INFO    :      0     0 45587.1010    0 1307 46633.6630 45587.1010  2.24%     -  659s
2023-08-03 18:52:56 INFO    :      0     0 45588.5025    0 1360 46633.6630 45588.5025  2.24%     -  662s
2023-08-03 18:52:59 INFO    :      0     0 45589.0838    0 1414 46633.6630 45589.0838  2.24%     -  666s
2023-08-03 18:53:00 INFO    :      0     0 45589.1436    0 1404 46633.6630 45589.1436  2.24%     -  666s
2023-08-03 18:53:03 INFO    :      0     0 45591.0427    0 1546 46633.6630 45591.0427  2.24%     -  669s
2023-08-03 18:53:05 INFO    :      0     0 46017.6407    0 1339 46633.6630 46017.6407  1.32%     -  671s
2023-08-03 18:53:08 INFO    :      0     0 46018.0654    0 1408 46633.6630 46018.0654  1.32%     -  674s
2023-08-03 18:53:08 INFO    :      0     0 46018.1448    0 1476 46633.6630 46018.1448  1.32%     -  674s
2023-08-03 18:53:12 INFO    :      0     0 46023.6230    0 1416 46633.6630 46023.6230  1.31%     -  678s
2023-08-03 18:53:18 INFO    :      0     0 46023.9356    0 1421 46633.6630 46023.9356  1.31%     -  684s
2023-08-03 18:53:18 INFO    :      0     0 46024.0480    0 1431 46633.6630 46024.0480  1.31%     -  684s
2023-08-03 18:53:21 INFO    :      0     0 46025.6811    0 1390 46633.6630 46025.6811  1.30%     -  687s
2023-08-03 18:53:23 INFO    :      0     0 46025.8652    0 1420 46633.6630 46025.8652  1.30%     -  689s
2023-08-03 18:53:23 INFO    :      0     0 46025.9193    0 1437 46633.6630 46025.9193  1.30%     -  689s
2023-08-03 18:53:26 INFO    :      0     0 46027.4110    0 1419 46633.6630 46027.4110  1.30%     -  692s
2023-08-03 18:53:28 INFO    :      0     0 46027.5796    0 1360 46633.6630 46027.5796  1.30%     -  694s
2023-08-03 18:53:30 INFO    :      0     0 46028.1743    0 1424 46633.6630 46028.1743  1.30%     -  696s
2023-08-03 18:53:32 INFO    :      0     0 46028.1743    0 1352 46633.6630 46028.1743  1.30%     -  698s
2023-08-03 18:53:48 INFO    :      0     2 46028.1743    0 1352 46633.6630 46028.1743  1.30%     -  714s
2023-08-03 18:53:49 INFO    :      1     5 46028.2490    1 1398 46633.6630 46028.1743  1.30%  3321  715s
2023-08-03 18:53:57 INFO    :      7    16 46030.1115    3 1545 46633.6630 46028.3302  1.30%  1861  723s
2023-08-03 18:54:01 INFO    :     15    24 46030.2483    4 1519 46633.6630 46028.7804  1.30%  2380  727s
2023-08-03 18:54:04 INFO    :     23    32 46030.2483    4 1519 46633.6630 46028.8572  1.30%  2358  730s
2023-08-03 18:54:06 INFO    : H   34    40                    46633.660540 46028.9416  1.30%  1951  732s
2023-08-03 18:54:10 INFO    :     60    75 46031.3031    6 1460 46633.6605 46028.9416  1.30%  1226  736s
2023-08-03 18:54:14 INFO    :     86   113 46030.2616    8 1515 46633.6605 46028.9416  1.30%   926  740s
2023-08-03 18:54:19 INFO    :    112   129 46030.2620    9 1519 46633.6605 46028.9416  1.30%   797  745s
2023-08-03 18:54:24 INFO    :    128   191 46030.2643    9 1522 46633.6605 46028.9416  1.30%   730  750s
2023-08-03 18:54:35 INFO    :    190   199 46030.3338   13 1495 46633.6605 46028.9416  1.30%   584  761s
2023-08-03 18:54:48 INFO    :    198   329 46030.4339   13 1493 46633.6605 46028.9416  1.30%   580  774s
2023-08-03 18:55:07 INFO    :    332   517 46031.0911   26 1466 46633.6605 46028.9416  1.30%   475  793s
2023-08-03 18:55:29 INFO    :    520   750 46032.3810   36 1452 46633.6605 46028.9416  1.30%   436  815s
2023-08-03 18:55:54 INFO    :    757   819 46035.7699   46 1413 46633.6605 46028.9416  1.30%   386  840s
2023-08-03 18:55:54 INFO    : H  779   819                    46633.656860 46028.9416  1.30%   385  840s
2023-08-03 18:56:25 INFO    :    826  1215 46040.4605   47 1405 46633.6569 46028.9416  1.30%   369  871s
2023-08-03 18:56:56 INFO    :   1227  1691 46038.7501   67 1348 46633.6569 46028.9416  1.30%   332  902s
2023-08-03 18:57:27 INFO    :   1723  2299 46041.7719   83 1365 46633.6569 46028.9416  1.30%   298  933s
2023-08-03 18:57:56 INFO    :   2351  2888 46042.4194  108 1362 46633.6569 46028.9416  1.30%   261  962s
2023-08-03 18:58:25 INFO    :   2940  3264 46044.2968  132 1333 46633.6569 46028.9416  1.30%   235  991s
2023-08-03 18:58:57 INFO    :   3332  3474 46044.6697  168 1300 46633.6569 46028.9416  1.30%   228 1023s
2023-08-03 18:59:35 INFO    :   3546  3972 46044.7246  188 1300 46633.6569 46028.9416  1.30%   226 1061s
2023-08-03 19:00:15 INFO    :   4061  4491 46046.4310  219 1223 46633.6569 46028.9416  1.30%   227 1101s
2023-08-03 19:00:59 INFO    :   4615  4926 46048.0039  273 1216 46633.6569 46028.9416  1.30%   228 1145s
2023-08-03 19:01:47 INFO    :   5070  5746 46052.9993  344 1116 46633.6569 46028.9416  1.30%   234 1193s
2023-08-03 19:02:33 INFO    :   5909  6243 46055.7125  474 1057 46633.6569 46028.9416  1.30%   227 1239s
2023-08-03 19:03:20 INFO    :   6439  7009 46060.4729  540  944 46633.6569 46028.9416  1.30%   226 1286s
2023-08-03 19:04:31 INFO    :   7240  7010 46129.7458  227  950 46633.6569 46028.9416  1.30%   223 1357s
2023-08-03 19:07:32 INFO    :   7242  7011 46038.5295   71 1125 46633.6569 46028.9416  1.30%   223 1539s
2023-08-03 19:09:18 INFO    :   7243  7012 46041.6529  135 1514 46633.6569 46028.9416  1.30%   223 1645s
2023-08-03 19:09:48 INFO    :   7244  7013 46037.0352  115 1557 46633.6569 46032.3505  1.29%   223 1675s
2023-08-03 19:10:09 INFO    :   7245  7013 46117.0866  152 1539 46633.6569 46035.6351  1.28%   223 1696s
2023-08-03 19:10:23 INFO    :   7246  7014 46208.1021  514 1516 46633.6569 46036.4342  1.28%   223 1709s
2023-08-03 19:10:31 INFO    :   7247  7015 46198.4651  228 1622 46633.6569 46037.0214  1.28%   223 1717s
2023-08-03 19:10:37 INFO    :   7248  7015 46064.9308  624 1622 46633.6569 46037.3955  1.28%   223 1723s
2023-08-03 19:10:42 INFO    :   7249  7016 46070.0306  224 1652 46633.6569 46037.4281  1.28%   223 1728s
2023-08-03 19:10:53 INFO    :   7251  7017 46052.0868  169 1668 46633.6569 46037.4414  1.28%   223 1739s
2023-08-03 19:11:40 INFO    :   7252  7018 46132.1691  113 1472 46633.6569 46047.7470  1.26%   223 1786s
2023-08-03 19:11:54 INFO    : 
2023-08-03 19:11:54 INFO    : Cutting planes:
2023-08-03 19:11:54 INFO    :   Gomory: 160
2023-08-03 19:11:54 INFO    :   Lift-and-project: 1
2023-08-03 19:11:54 INFO    :   Cover: 53
2023-08-03 19:11:54 INFO    :   Implied bound: 490
2023-08-03 19:11:54 INFO    :   Projected implied bound: 68
2023-08-03 19:11:54 INFO    :   Clique: 111
2023-08-03 19:11:54 INFO    :   MIR: 458
2023-08-03 19:11:54 INFO    :   StrongCG: 7
2023-08-03 19:11:54 INFO    :   Flow cover: 1182
2023-08-03 19:11:54 INFO    :   GUB cover: 8
2023-08-03 19:11:54 INFO    :   Zero half: 4
2023-08-03 19:11:54 INFO    :   Network: 1
2023-08-03 19:11:54 INFO    :   RLT: 107
2023-08-03 19:11:54 INFO    :   Relax-and-lift: 566
2023-08-03 19:11:54 INFO    : 
2023-08-03 19:11:54 INFO    : Explored 7252 nodes (2093954 simplex iterations) in 1800.86 seconds (2898.39 work units)
2023-08-03 19:11:54 INFO    : Thread count was 16 (of 16 available processors)
2023-08-03 19:11:54 INFO    : 
2023-08-03 19:11:54 INFO    : Solution count 10: 46633.7 46633.7 46633.7 ... 46652.3
2023-08-03 19:11:54 INFO    : 
2023-08-03 19:11:54 INFO    : Time limit reached
2023-08-03 19:11:54 INFO    : Best objective 4.663365686000e+04, best bound 4.604774697599e+04, gap 1.2564%

I have the idea that somewhere in my model formulation something can be improved considerably to make Gurobi coverge faster. My model may also contain numerical issues, but this does not always seem to be the case given the coefficient statistics. I'm also not sure about the way I've defined the objective function now. Components 3, 4 and 5, do they indeed help lead Gurobi to a solution or is this not the right way? And what kind of weighting could I use for this, if I actually don't want them to influence the optimal solution? Suggestions to further tighten the model are also welcome. What do you think of constraints G11* and G12*? Are they better than the original ones like this, in terms of solving performance?

Apologies for the many questions, but I hope that someone with more knowledge is willing to take the time to see what is wrong with or can be improved in my model. Thanks a lot in advance!

Best regards,

Koen Timmermans

Related to

0

Comments

2 comments

Date Votes
  • Mario Ruthmair
    • Gurobi Staff Gurobi Staff

    Hi Koen,

    I quickly scanned through your message and try to answer at least some of your questions:

    • In general, VRPs are notoriously difficult to solve. State-of-the-art algorithms involve some of the most complicated MILP techniques (branch-price-and-cut, many additional valid inequalities, sophisticated algorithms to solve the pricing subproblems, etc.) based on the set partitioning formulation. The Big-M or other compact formulations are usually much less efficient since they provide weak dual bounds.
    • You already did a lot based on the Big-M formulation you have, and there is not much more I can add except for working on the formulation. Although you would probably not obtain the performance of state-of-the-art methods, you can use different modeling approaches that usually perform a bit better. You can find a few ideas in the Jupyter notebooks in this Git repository.
    • If you see a longer break in the output, this usually means that Gurobi launches some other algorithms internally. For model 09 you see a huge jump in the dual bound obtained in such an internal algorithm.
    • model 10: The bound range is not too bad, except for the lower end of the Bounds interval. There seem to be some variable bounds that are at 1e-13. These probably can be rounded off to zero, right?
    • model 10: The ordering phase is part of the barrier algorithm to solve the root relaxation. It is not necessary to improve this since you see below that the root relaxation has actually been solved by another algorithm ("Solved with dual simplex"). By default, barrier and simplex run in parallel and see who solves it first.

    Best regards,
    Mario

    0
  • Koen Timmermans
    • Gurobi-versary
    • Conversationalist
    • Curious

    Hi Mario,

    Thank you for your explanation!

    Based on your Git repository I have changed my formulation to one without using the index k for the vehicles. This reduced the number of variables, constraints and non-zeros dramatically. It was very helpful, thanks!

    The other "problems" that I had also seem to be resolved.

    Best regards,

    Koen Timmermans

    0

Please sign in to leave a comment.

Didn't find what you were looking for?

New post