MIP Logging#
The MIP log can be divided into three sections: the presolve section, the simplex progress section, and the summary section.
Presolve Section#
As with the simplex and barrier logs, the first section of the MIP log
is the presolve section. Here is presolve output for MIPLIB model
mas76:
Presolve removed 0 rows and 3 columns
Presolve time: 0.01s
Presolved: 12 rows, 148 columns, 1615 nonzeros
Variable types: 1 continuous, 147 integer (145 binary)
In this example, presolve was able to remove 3 columns. The last two lines show the size of the model that is passed to the branch-and-cut algorithm and the types of remaining variables.
Progress Section#
The next section in the MIP log tracks the progress of the
branch-and-cut search. The search involves a number of different steps,
so this section typically contains a lot of detailed information. The
first thing to observe in the log for example mas76 is this line:
Found heuristic solution: objective 157344.61033
It indicates that the Gurobi heuristics found an integer-feasible solution before the root relaxation was solved.
The next thing you will see in the log is the root relaxation solution display. For a model where the root solves quickly, this display contains a single line:
Root relaxation: objective 3.889390e+04, 50 iterations, 0.00 seconds
For models where the root relaxation takes more time (MIPLIB model
dano3mip, for example), the Gurobi solver will automatically include
a detailed simplex log for the relaxation itself:
Root simplex log...
Iteration Objective Primal Inf. Dual Inf. Time
15338 5.7472018e+02 6.953458e+04 0.000000e+00 5s
19787 5.7623162e+02 0.000000e+00 0.000000e+00 7s
Root relaxation: objective 5.762316e+02, 19787 iterations, 6.18 seconds
To be more precise, this more detailed log is triggered whenever the time to solve the root relaxation exceeds the DisplayInterval parameter value (5 seconds by default).
The next section provides progress information on the branch-and-cut tree search:
Nodes | Current Node | Objective Bounds | Work
Expl Unexpl | Obj Depth IntInf | Incumbent BestBd Gap | It/Node Time
0 0 38893.9036 0 11 157344.610 38893.9036 75.3% - 0s
H 0 0 80297.610430 38893.9036 51.6% - 0s
H 0 0 60361.518931 38893.9036 35.6% - 0s
H 0 0 41203.601476 38893.9036 5.61% - 0s
0 0 38923.3264 0 12 41203.6015 38923.3264 5.53% - 0s
0 0 38923.3264 0 12 41203.6015 38923.3264 5.53% - 0s
H 0 0 40697.054142 38923.3264 4.36% - 0s
0 0 38923.3264 0 13 40697.0541 38923.3264 4.36% - 0s
H 0 0 40005.054142 38923.3264 2.70% - 0s
0 0 38939.3131 0 15 40005.0541 38939.3131 2.66% - 0s
0 0 38964.7042 0 13 40005.0541 38964.7042 2.60% - 0s
0 0 39004.6387 0 15 40005.0541 39004.6387 2.50% - 0s
0 0 39008.7922 0 15 40005.0541 39008.7922 2.49% - 0s
0 0 39008.9356 0 12 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 14 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 15 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 15 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 16 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 17 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 17 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 19 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 18 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 18 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 19 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 19 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 18 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 18 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 18 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 18 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 18 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 19 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 21 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 21 40005.0541 39008.9356 2.49% - 0s
0 0 39008.9356 0 19 40005.0541 39008.9356 2.49% - 0s
0 2 39008.9356 0 19 40005.0541 39008.9356 2.49% - 0s
This display is somewhat dense with information, but each column is
hopefully fairly easy to understand. The Nodes section (the first
two columns) provides general quantitative information on the progress
of the search. The first column shows the number of branch-and-cut nodes
that have been explored to that point, while the second shows the number
of leaf nodes in the search tree that remain unexplored. At times, there
will be an H or * character at the beginning of the output line.
These indicate that a new feasible solution has been found, either by a
MIP heuristic (H) or by branching (*).
The Current Node section provides information on the specific node
that was explored at that point in the branch-and-cut tree. It shows the
objective of the associated relaxation, the depth of that node in the
branch-and-cut tree, and the number of integer variables that have
non-integral values in the associated relaxation.
The Objective Bounds section provides information on the best known
objective value for a feasible solution (i.e., the objective value of
the current incumbent), and the current objective bound provided by leaf
nodes of the search tree. The optimal objective value is always between
these two values. The third column in this section (Gap) shows the
relative gap between the two objective bounds. When this gap is smaller
than the MIPGap parameter, optimization terminates.
The Work section of the log provides information on how much work
has been performed to that point. The first column shows the average
number of simplex iterations performed per node in the branch-and-cut
tree. The final column shows the elapsed time since the solve began.
By default, the Gurobi MIP solver prints a log line every 5 seconds (although the interval can sometimes be longer for models with particularly time-consuming nodes). The interval between log lines can be adjusted with the DisplayInterval parameter (see the Parameters section of this document for more information).
Note that the explored node count often stays at 0 for an extended period. This means that the Gurobi MIP solver is processing the root node. The Gurobi solver can often expend a significant amount of effort on the root node, generating cutting planes and trying various heuristics in order to reduce the size of the subsequent branch-and-cut tree.
Summary Section#
The third section in the log provides summary information once the MIP solver has finished:
Cutting planes:
Gomory: 1
MIR: 17
Explored 313128 nodes (1741251 simplex iterations) in 4.80 seconds
Thread count was 8 (of 8 available processors)
Solution count 7: 40005.1 40697.1 41203.6 ... 157345
Optimal solution found (tolerance 1.00e-04)
Best objective 4.000505414200e+04, best bound 4.000505414200e+04, gap 0.0000%
In this example, the Gurobi solver required just under 5 seconds to
solve the model to optimality, and it used 8 threads to do so (the
thread count can be limited with the Threads parameter).
The solution count provides the number of solutions found during the
optimization process (7 in this case). If the number exceeds 10, then
only the best 10 solutions are listed in this log line. The gap between
the best feasible solution objective and the best bound is 0.0%, which
produces an Optimal termination status, since the achieved gap is
smaller than the default MIPGap parameter value.