Skip to main content

Interpreting the log file for the branch-and-cut tree search

Answered

Comments

6 comments

  • Matthias Miltenberger
    Gurobi Staff Gurobi Staff

    Hi Marcus,

    It's not too easy to give advice just by seeing this (incomplete) log file. Could you please edit your post and also include the problem statistics from the beginning?

    What I noticed is that the node throughput is pretty bad, most likely due to the relatively high iteration count per node (second to last column). Root node processing is also taking quite a long time, so you might try disabling cutting planes - especially since there is no objective function to guide the process.

    Judging by the number of integer infeasibilities, your shared log does not seem to be close to being finished with the optimization.

    You might want to give the NoRel heuristic a shot (NoRelHeurTime).

    It could also very well be that this is simply a very hard problem that is not solvable in an acceptable time frame.

    Best regards,
    Matthias

    0
  • Marcus Garvie
    Conversationalist
    First Question

    Hi Mathias,

    thank you for your comments. Yes I do know that the problem I am trying to solve was deliberately constructed to be difficult. When you suggest disabling cutting planes do you mean set Cuts=0 ?  What value do you suggest for the NoRelHeurTime? I have included the full (up-to-date) log file below.

    Marcus.

    PS I should mention that although the natural objective function for my problem is zero, I found improved performance by adding an 'artificial' objective function equal to the sum of the variables (which I know for a feasible solution is 209).

     

    marcusgarvie@Marcuss-MacBook-Pro LPfiles % gurobi_cl ResultFile=subregion6_alt.sol SolutionLimit=1 Method=3 MIPFocus=1 Heuristics=1 subregion6_alt.lp
    Set parameter Username
    Set parameter SolutionLimit to value 1
    Set parameter Method to value 3
    Set parameter Heuristics to value 1
    Set parameter MIPFocus to value 1
    Set parameter LogFile to value "gurobi.log"
     
    Gurobi Optimizer version 9.5.0
     
    Read LP format model from file subregion6_alt.lp
    Reading time = 7.84 seconds
    Obj: 7733 rows, 1372296 columns, 50774952 nonzeros
    Thread count: 10 physical cores, 10 logical processors, using up to 10 threads
    Optimize a model with 7733 rows, 1372296 columns and 50774952 nonzeros
    Model fingerprint: 0x789d375f
    Variable types: 0 continuous, 1372296 integer (1372296 binary)
    Coefficient statistics:
      Matrix range     [1e+00, 1e+00]
      Objective range  [1e+00, 1e+00]
      Bounds range     [1e+00, 1e+00]
      RHS range        [1e+00, 1e+00]
    Presolve removed 96 rows and 0 columns (presolve time = 6s) ...
    Presolve removed 96 rows and 97704 columns (presolve time = 10s) ...
    Presolve removed 96 rows and 97704 columns (presolve time = 15s) ...
    Presolve removed 96 rows and 97704 columns (presolve time = 20s) ...
    Presolve removed 96 rows and 97704 columns (presolve time = 25s) ...
    Presolve removed 504 rows and 97704 columns (presolve time = 30s) ...
    Presolve removed 504 rows and 97704 columns (presolve time = 35s) ...
    Presolve removed 504 rows and 97704 columns (presolve time = 40s) ...
    Presolve removed 504 rows and 97704 columns (presolve time = 45s) ...
    Presolve removed 504 rows and 97704 columns (presolve time = 51s) ...
    Presolve removed 504 rows and 97704 columns
    Presolve time: 52.18s
    Presolved: 7229 rows, 1274592 columns, 46970412 nonzeros
    Variable types: 0 continuous, 1274592 integer (1274592 binary)
     
    Concurrent LP optimizer: primal simplex, dual simplex, and barrier
    Showing barrier log only...
     
    Root barrier log...
     
    Ordering time: 0.03s
     
    Barrier statistics:
     AA' NZ     : 1.412e+06
     Factor NZ  : 3.275e+06 (roughly 500 MB of memory)
     Factor Ops : 2.402e+09 (less than 1 second per iteration)
     Threads    : 8
     
                      Objective                Residual
    Iter       Primal          Dual         Primal    Dual     Compl     Time
       0   8.56184000e+04  2.09000000e+02  7.52e+02 8.52e-14  2.50e-03    86s
       1   9.91639026e+02  1.98823220e+02  6.89e+00 8.88e-16  2.68e-05    87s
       2   2.47693217e+02  2.01312109e+02  3.41e-01 6.66e-16  3.97e-06    87s
       3   2.09000000e+02  2.08252626e+02  4.23e-14 9.99e-16  2.93e-07    88s
       4   2.09000000e+02  2.08999253e+02  1.10e-13 8.88e-16  2.93e-10    88s
       5   2.09000000e+02  2.09000000e+02  1.14e-13 7.99e-16  2.95e-16    89s
     
    Barrier solved model in 5 iterations and 88.94 seconds (188.88 work units)
    Optimal objective 2.09000000e+02
     
      Building initial crossover basis                               102s
      Building initial crossover basis                               105s
      Building initial crossover basis                               111s
      Building initial crossover basis                               115s
     
    Root crossover log...
     
        3420 variables added to crossover basis                      120s
     
         289 DPushes remaining with DInf 0.0000000e+00               124s
           0 DPushes remaining with DInf 0.0000000e+00               125s
     
           1 PPushes remaining with PInf 0.0000000e+00               125s
           0 PPushes remaining with PInf 0.0000000e+00               125s
     
      Push phase complete: Pinf 0.0000000e+00, Dinf 2.1177851e-09    125s
     
     
    Root simplex log...
     
    Iteration    Objective       Primal Inf.    Dual Inf.      Time
         128    2.0900000e+02   0.000000e+00   0.000000e+00    125s
         128    2.0900000e+02   0.000000e+00   0.000000e+00    126s
     
    Solved with barrier
     
    Root relaxation: objective 2.090000e+02, 128 iterations, 64.40 seconds (98.46 work units)
     
        Nodes    |    Current Node    |     Objective Bounds      |     Work
     Expl Unexpl |  Obj  Depth IntInf | Incumbent    BestBd   Gap | It/Node Time
     
         0     0  209.00000    0 4908          -  209.00000      -     -  921s
         0     0  209.00000    0 4913          -  209.00000      -     - 2742s
         0     0  209.00000    0 4900          -  209.00000      -     - 3238s
         0     0  209.00000    0 4933          -  209.00000      -     - 4606s
         0     0  209.00000    0 4924          -  209.00000      -     - 5112s
         0     0  209.00000    0 5128          -  209.00000      -     - 6159s
         0     0  209.00000    0 4612          -  209.00000      -     - 6973s
         0     0  209.00000    0 5038          -  209.00000      -     - 7959s
         0     0  209.00000    0 4920          -  209.00000      -     - 8750s
         0     0  209.00000    0 4958          -  209.00000      -     - 10030s
         0     0  209.00000    0 4948          -  209.00000      -     - 10499s
         0     0  209.00000    0 4988          -  209.00000      -     - 11659s
         0     0  209.00000    0 4920          -  209.00000      -     - 12128s
         0     0  209.00000    0 5018          -  209.00000      -     - 13183s
         0     0  209.00000    0 4942          -  209.00000      -     - 13718s
         0     0  209.00000    0 5125          -  209.00000      -     - 14689s
         0     2  209.00000    0 5125          -  209.00000      -     - 159750s
         1     5  209.00000    1 5009          -  209.00000      -  8273 160239s
         3     8  209.00000    2 5027          -  209.00000      -  7430 160975s
         7    16  209.00000    3 5037          -  209.00000      -  7339 161828s
        15    26  209.00000    4 4961          -  209.00000      -  9060 163644s
        25    36  209.00000    5 5031          -  209.00000      - 14507 163736s
        35    46  209.00000    5 5024          -  209.00000      - 11711 163833s
        45    56  209.00000    6 5044          -  209.00000      - 10103 163906s
        55    70  209.00000    6 5026          -  209.00000      -  8747 164033s
        69    89  209.00000    7 5042          -  209.00000      -  7799 164133s
        88   105  209.00000    8 5041          -  209.00000      -  6613 164244s
       104   165  209.00000    9 5046          -  209.00000      -  6149 164591s
       164   286  209.00000   11 5045          -  209.00000      -  5065 165382s
       285   521  209.00000   16 5005          -  209.00000      -  4481 166999s
       520   738  209.00000   29 4904          -  209.00000      -  4390 168607s
       737   923  209.00000   38 4838          -  209.00000      -  4484 170349s
       922  1113  209.00000   50 4810          -  209.00000      -  4840 172089s
      1116  1305  209.00000   61 4816          -  209.00000      -  5111 173903s
      1308  1473  209.00000   66 4590          -  209.00000      -  5393 176768s
      1476  1642  209.00000   67 4614          -  209.00000      -  5632 178917s
      1645  1804  209.00000   71 4590          -  209.00000      -  5994 182544s
      1807  1970  209.00000   74 4597          -  209.00000      -  6294 185149s
      1973  2116  209.00000   77 4600          -  209.00000      -  6607 188706s
      2121  2271  209.00000   78 4597          -  209.00000      -  6800 191097s
      2276  2426  209.00000   80 4604          -  209.00000      -  7070 193963s
      2431  2541  209.00000   84 4584          -  209.00000      -  7417 196756s
      2548  2635  209.00000   86 4561          -  209.00000      -  7651 199034s
      2642  2758  209.00000   87 4567          -  209.00000      -  7716 203105s
      2765  2858  209.00000   88 4566          -  209.00000      -  7955 207474s
      2865  2928  209.00000   90 4571          -  209.00000      -  8224 211357s
      2935  3008  209.00000   92 4492          -  209.00000      -  8475 219566s
      3015  3082  209.00000   94 4516          -  209.00000      -  8762 227684s
      3089  3150  209.00000   96 4473          -  209.00000      -  9219 250004s
      3157  3212  209.00000   99 4472          -  209.00000      -  9567 254023s
      3221  3272  209.00000  100 4439          -  209.00000      -  9575 258520s
      3281  3324  209.00000  104 4407          -  209.00000      -  9837 327066s
      3335  3369  209.00000  105 4418          -  209.00000      - 10571 331467s
      3380  3424  209.00000  108 4408          -  209.00000      - 10711 336330s
      3435  3470  209.00000  111 4395          -  209.00000      - 10866 422490s
      3481  3542  209.00000  114 4358          -  209.00000      - 11622 425978s
      3555  3603  209.00000  116 4383          -  209.00000      - 11539 435370s
      3616  3646  209.00000  117 4379          -  209.00000      - 11825 514786s
      3663  3731  209.00000  120 4367          -  209.00000      - 12570 520098s
      3750  3802  209.00000  123 4387          -  209.00000      - 12725 529575s
      3821  3864  209.00000  125 4395          -  209.00000      - 12903 561905s
      3883  3923  209.00000  126 4362          -  209.00000      - 13245 600795s
      3944  3998  209.00000  128 4380          -  209.00000      - 13676 605973s
    0
  • Matthias Miltenberger
    Gurobi Staff Gurobi Staff

    Hi Marcus,

    You are trying to solve a feasibility problem and apparently a pretty hard one. As you can see from the node log, there is no visible progress and you might be still very far away from a solution. I suggest focussing on heuristics for this model, so MIPFOCUS=1 or Heuristics=0.2.

    Yes, Cuts=0 disables cutting planes and is the parameter I was referring to earlier.

    Since you don't have a meaningful objective, it is difficult to guide Gurobi towards a solution using some parameter settings.

    If your deliberate goal was to come up with a hard model instance, then I guess you succeeded :-)

    Cheers,
    Matthias

    0
  • Marcus Garvie
    Conversationalist
    First Question

    Hi Matthias,

    we didn't deliberately construct a hard model. After a years' worth of work we managed to convert the Eternity puzzle into an LP problem. This is a notoriously difficult tiling problem. You say that there is 'no visible progress' in the node log. Which column of data is telling you this and why?

    Thank you,

    Marcus.

    0
  • Matthias Miltenberger
    Gurobi Staff Gurobi Staff

    Hi Marcus,

    Well, the first column shows the number of explored nodes, while the second shows the number of yet to be inspected nodes. It looks like the numbers are still increasing, so there is no end in sight, yet.

    The column that counts the integer infeasibilities is also not decreasing significantly.

    And to make matters worse, the node throughput is very bad with every (later) new line in the log (roughly 100 nodes) taking several hours.

    By the way, I was only quoting you concerning the difficulty of the problem:
    "Yes I do know that the problem I am trying to solve was deliberately constructed to be difficult."

    And I suppose the no-free-lunch-theorem also applies here: reformulating the problem does not necessarily make it any easier to solve.

    Cheers,
    Matthias

    0
  • Marcus Garvie
    Conversationalist
    First Question

    Thank you Matthias,

    that is very helpful. So as I explore the effect of different parameter sets I know what to look for.

    Best,

    Marcus.

    0

Please sign in to leave a comment.