Distributed MIP Logging
Logging for distributed MIP is very similar to the standard MIP logging. The main differences are in the progress section. The header for the standard MIP logging looks like this:
Nodes | Current Node | Objective Bounds | Work
Expl Unexpl | Obj Depth IntInf | Incumbent BestBd Gap | It/Node Time
By contrast, the distributed MIP header looks like this:
Nodes | Utilizaiton | Objective Bounds | Work
Expl Unexpl | Active Sync Comm | Incumbent BestBd Gap | It/Node Time
You'll note that columns three through five show different
information. In the distributed MIP log, these columns give
information about the utilization of the distributed workers,
expressed as percentages. The first of these columns shows the
fraction of the preceding time period (the time since the previous
progress log line) that the workers spent actively processing MIP
nodes. The second column shows the time the workers spent waiting for
other workers to complete tasks assigned to them. The final column
shows the time spent communicating data between machines. The numbers
sum to 100%.
Here is an example of a distributed MIP progress log:
Nodes | Utilization | Objective Bounds | Work
Expl Unexpl | Active Sync Comm | Incumbent BestBd Gap | It/Node Time
* 0 - 157344.61033 - - - 0s
* 0 - 41359.940833 - - - 0s
* 0 - 25050.545455 - - - 0s
* 0 - 18150.083886 - - - 0s
* 0 - 14372.871258 - - - 0s
* 0 - 13725.475382 - - - 0s
* 261 - 13570.462316 - - - 0s
* 0 - 13308.140897 - - - 0s
* 747 - 12821.371258 - - - 0s
262 149 99% 0% 0% 12821.3713 10617.6273 17.2% 3.4 0s
* 1060 - 12356.371258 10617.6273 14.1% - 0s
* 2413 - 12010.589689 10617.6273 11.6% - 0s
Ramp-up phase complete - continuing with instance 4 (best bd 10669.8)
* 6881 - 11956.589689 10669.8486 10.8% - 2s
* 6951 - 11945.263051 10669.8486 10.7% - 2s
*101868 - 11891.263051 10943.0036 7.97% - 2s
*614787 - 11857.371258 11136.5161 6.08% - 4s
1140819 388613 99% 1% 0% 11857.3713 11231.3942 5.28% 4.6 5s
*1946490 - 11801.185729 11306.6196 4.19% - 8s
2683258 497092 86% 14% 1% 11801.1857 11364.3331 3.70% 4.6 10s
4143934 185856 69% 4% 26% 11801.1857 11468.7845 2.82% 4.4 15s
4569003 21 57% 2% 41% 11801.1857 11800.6434 0.00% 4.4 18s
One thing you may find in the progress section is that node counts may not increase monotonically. In this example, a solution found at node 261 is reported before a solution found at node 0. Distributed MIP tries to create a single, unified view of node numbers, but with multiple machines processing nodes independently, possibly at different rates, some inconsistencies are inevitable.
Another difference is the line that indicates that the distributed ramp-up phase is complete. At this point, the distributed strategy transitions from a concurrent approach to a distributed approach. The log line indicates which worker was the winner in the concurrent approach. Distributed MIP continues by dividing the partially explored MIP search tree from this worker among all of the workers.
Another difference in the distributed log is in the summary section. The distributed MIP log includes a breakdown of how runtime was spent:
Runtime breakdown: Active: 13.73s (75%) Sync: 1.16s (6%) Comm: 3.45s (19%)This is an aggregated view of the utilization data that is displayed in the progress log lines. In this example, the workers spent 75% of runtime actively working on MIP nodes, 6% waiting to synchronize with other workers, and 19% communicating data between machines.
