Matheuristic: Injecting Heuristic Solutions more regularly
ユーザーの入力を待っています。Hi all,
I'm implementing a matheuristic using Gurobi and I’m encountering challenges with achieving a smooth "Ping-Pong" interaction between the solver and my custom heuristic.
Goal:
My objective is to create an iterative loop where Gurobi and my heuristic alternate consistently, after Gurobi has found a lower bound at the root node.
1. Extract the best incumbent solution.
2. Apply a heuristic to improve the solution.
3. Inject the new heuristic solution into the solver.
4. Gurobi explores the injected solution.
5. Repeat.
Current Approach:
I’m using the MIPNODE callback to trigger the heuristic after a timeout and inject a new solution into the gurobi solver using cbSetSolution() and cbUseSolution().
Challenges:
1. Delayed Solver Response to Heuristic Solutions:
Sometimes, Gurobi improves upon the injected solution within seconds, but in other cases, it takes 30+ minutes.
2. MIPNODE Callback Is Triggered Too Infrequently:
Once the initial improvement is done, the MIPNODE callback is rarely called again, often with gaps of 30+ minutes. This blocks my heuristic from participating regularly in the process. I also tested MIP callback, but it didn’t offer more responsive timing for solution injection.
Below, I've included a simplified version of my code, an example console output and an example Gurobi log.
Any suggestions on how to trigger MIPNODE more frequently and maintain an active feedback loop between heuristic and solver or on how to restructure the approach to better support this "Ping Pong" pattern would be greatly appreciated!
Thanks in advance for your insights and support!
Best regards,
Konstantin
model = gp.Model("Matheuristic")
build_model()
variable_initialization()
model.optimize(my_callback)
def my_callback(model, where):
if where == GRB.Callback.MIPSOL:
model._last_incumbent_time = model.cbGet(GRB.Callback.RUNTIME)
model._last_alns_solution = None
model._last_best_vars = model.cbGetSolution(model._vars)
elif where == GRB.Callback.MIPNODE:
current_time = model.cbGet(GRB.Callback.RUNTIME)
if (model._last_alns_solution is None
and current_time - model._last_incumbent_time > model._timeout):
new_vars, new_vals= heuristic(model._last_best_vars)
model.cbSetSolution(new_vars, new_vals)
model._last_alns_solution = model.cbUseSolution()[MIPSOL@1] New incumbent found: obj = 27025.00
[MIPSOL@1] First solution detected.
[MIPSOL@2] New incumbent found: obj = 27025.00
[MIPNODE@1623]
[MIPNODE@1623] Call ALNS...
[ALNS@1957]: Started.
[ALNS@1957]: ALNS ended with obj=23804.00.
[MIPNODE@1966]: ALNS solution injected with obj = 23804.00
[MIPSOL@1972] New incumbent found: obj = 23804.00
[MIPSOL@1976] New incumbent found: obj = 23788.00
[MIPNODE@2432]
[MIPNODE@2432] Call ALNS...
[ALNS@2432]: Started.
[ALNS@2744]: ALNS ended with obj=23748.00.
[MIPNODE@2758]: ALNS solution injected with obj = 23748.00
[MIPSOL@4380] New incumbent found: obj = 23748.00
[MIPNODE@5380]
[MIPNODE@5380] Call ALNS...
[ALNS@5380]: Started.
[ALNS@5400]: ALNS ended with obj=23748.00.
[MIPNODE@5400] ALNS solution not injected, because new_obj = 23748.00 >= 23748.00 = cur_objGurobi 12.0.2 (linux64) logging started Wed Jul 30 11:36:34 2025
Set parameter LogFile to value "Exact_Approach/Computational_Study/ALNS_Test_Server_v3/3_Runs/run_instance_d25_t24_p1200_f1200_s42_nhtu1_p1_fpt1_ftr6_htu300_ft200/1_Gurobi_Log.txt"
Set parameter MIPGap to value 0
Set parameter Threads to value 6
Set parameter TimeLimit to value 5400
Gurobi Optimizer version 12.0.2 build v12.0.2rc0 (linux64 - "SUSE Linux Enterprise Server 15 SP6")
CPU model: Intel(R) Xeon(R) Platinum 8380 CPU @ 2.30GHz, instruction set [SSE2|AVX|AVX2|AVX512]
Thread count: 80 physical cores, 160 logical processors, using up to 6 threads
Non-default parameters:
TimeLimit 5400
MIPGap 0
LogToConsole 0
Seed 42
Threads 6
Optimize a model with 2216696 rows, 936408 columns and 4478978 nonzeros
Model fingerprint: 0x5c90f4b1
Variable types: 0 continuous, 936408 integer (936308 binary)
Coefficient statistics:
Matrix range [1e+00, 2e+01]
Objective range [1e+00, 3e+02]
Bounds range [1e+00, 1e+00]
RHS range [1e+00, 1e+02]
User MIP start produced solution with objective 27025 (2.07s)
Loaded user MIP start with objective 27025
Processed MIP start in 2.59 seconds (1.04 work units)
Presolve removed 1564569 rows and 480942 columns (presolve time = 5s)...
Presolve removed 1584068 rows and 499903 columns (presolve time = 10s)...
Presolve removed 1584145 rows and 499972 columns (presolve time = 16s)...
Presolve removed 1584263 rows and 503363 columns
Presolve time: 19.77s
Presolved: 632433 rows, 433045 columns, 1849149 nonzeros
Variable types: 0 continuous, 433045 integer (433042 binary)
Deterministic concurrent LP optimizer: primal simplex, dual simplex, and barrier
Showing barrier log only...
Root barrier log...
Ordering time: 0.92s
Barrier statistics:
Dense cols : 17
AA' NZ : 1.981e+06
Factor NZ : 1.291e+07 (roughly 500 MB of memory)
Factor Ops : 7.039e+08 (less than 1 second per iteration)
Threads : 4
Objective Residual
Iter Primal Dual Primal Dual Compl Time
0 1.33318091e+07 -4.23147448e+07 2.58e+03 1.74e+01 1.85e+03 28s
1 6.58043965e+06 -4.08197280e+07 1.26e+03 1.73e+00 6.07e+02 29s
2 6.17351422e+06 -4.80940080e+07 1.18e+03 2.37e-08 7.69e+02 30s
3 2.84814902e+05 -4.27902640e+07 4.85e+01 3.18e-08 6.11e+01 31s
4 7.86936708e+04 -1.58497336e+07 8.18e+00 1.09e-08 1.48e+01 31s
5 3.90454781e+04 -3.37029171e+06 2.46e-02 7.68e-09 2.63e+00 32s
6 3.78134205e+04 -8.16598074e+05 4.09e-06 3.36e-09 6.59e-01 33s
7 3.52938385e+04 -2.37981446e+05 1.25e-08 1.42e-09 2.11e-01 33s
8 3.18634860e+04 -1.11739461e+05 5.10e-09 7.93e-10 1.11e-01 34s
9 2.87866155e+04 -6.85506675e+04 3.17e-09 4.65e-10 7.50e-02 35s
10 2.58905221e+04 -2.51740053e+04 1.56e-09 3.18e-10 3.94e-02 36s
11 2.45574690e+04 4.66135011e+03 9.10e-10 1.12e-10 1.53e-02 36s
12 2.40156898e+04 8.21113440e+03 6.91e-10 8.89e-11 1.22e-02 37s
13 2.36595931e+04 1.49136777e+04 5.52e-10 4.27e-11 6.74e-03 38s
14 2.30195173e+04 1.80422702e+04 3.16e-10 2.38e-11 3.84e-03 38s
15 2.27258984e+04 1.98841919e+04 2.29e-10 2.32e-11 2.19e-03 39s
16 2.26561701e+04 2.00326396e+04 2.11e-10 2.57e-11 2.02e-03 40s
17 2.25168904e+04 2.03597422e+04 1.73e-10 2.55e-11 1.66e-03 40s
18 2.24638825e+04 2.05949862e+04 1.55e-10 2.80e-11 1.44e-03 41s
19 2.24031030e+04 2.08542407e+04 1.38e-10 3.89e-11 1.19e-03 42s
20 2.23748621e+04 2.10295196e+04 1.27e-10 4.00e-11 1.04e-03 43s
21 2.23001053e+04 2.11509841e+04 1.04e-10 4.02e-11 8.86e-04 44s
22 2.22627253e+04 2.12471453e+04 9.18e-11 4.00e-11 7.83e-04 44s
23 2.22295598e+04 2.14111807e+04 7.96e-11 3.93e-11 6.31e-04 45s
24 2.21589844e+04 2.14953015e+04 5.23e-11 3.75e-11 5.12e-04 46s
25 2.21309334e+04 2.16968136e+04 4.06e-11 3.21e-11 3.35e-04 47s
26 2.21192342e+04 2.17586098e+04 3.57e-11 3.02e-11 2.78e-04 48s
27 2.20946244e+04 2.18214317e+04 2.50e-11 3.16e-11 2.11e-04 49s
28 2.20853622e+04 2.19121896e+04 2.11e-11 1.58e-11 1.34e-04 50s
29 2.20607445e+04 2.19543744e+04 1.09e-11 1.28e-11 8.20e-05 51s
30 2.20523726e+04 2.19825596e+04 1.12e-11 3.07e-12 5.38e-05 52s
31 2.20495483e+04 2.19880588e+04 9.01e-12 3.30e-12 4.74e-05 52s
32 2.20484789e+04 2.19951266e+04 8.19e-12 2.16e-12 4.11e-05 53s
33 2.20480609e+04 2.19982001e+04 7.83e-12 1.93e-12 3.84e-05 54s
34 2.20455860e+04 2.20072074e+04 6.05e-12 1.25e-12 2.96e-05 54s
35 2.20449391e+04 2.20098972e+04 5.46e-12 1.59e-12 2.70e-05 55s
36 2.20445268e+04 2.20162444e+04 5.08e-12 2.61e-12 2.18e-05 56s
37 2.20439968e+04 2.20188748e+04 4.77e-12 3.75e-12 1.94e-05 57s
38 2.20424913e+04 2.20227877e+04 1.36e-11 7.16e-12 1.52e-05 58s
39 2.20415739e+04 2.20278142e+04 1.33e-11 1.07e-11 1.06e-05 59s
40 2.20401055e+04 2.20310248e+04 1.39e-10 1.47e-11 7.00e-06 60s
41 2.20397788e+04 2.20349598e+04 2.51e-10 6.82e-12 3.72e-06 61s
42 2.20387157e+04 2.20366099e+04 1.03e-09 3.30e-12 1.62e-06 63s
43 2.20384926e+04 2.20372814e+04 3.70e-09 2.16e-12 9.34e-07 65s
44 2.20384590e+04 2.20377355e+04 2.25e-09 1.59e-12 5.58e-07 66s
45 2.20384000e+04 2.20383573e+04 2.80e-09 9.95e-13 3.29e-08 68s
46 2.20383848e+04 2.20383847e+04 2.66e-10 3.47e-11 3.83e-11 68s
Barrier solved model in 46 iterations and 68.24 seconds (38.16 work units)
Optimal objective 2.20383848e+04
Root crossover log...
52933 DPushes remaining with DInf 0.0000000e+00 69s
0 DPushes remaining with DInf 0.0000000e+00 70s
125362 PPushes remaining with PInf 0.0000000e+00 70s
96903 PPushes remaining with PInf 0.0000000e+00 181s
84356 PPushes remaining with PInf 0.0000000e+00 222s
76796 PPushes remaining with PInf 0.0000000e+00 253s
75535 PPushes remaining with PInf 0.0000000e+00 258s
48638 PPushes remaining with PInf 0.0000000e+00 260s
11079 PPushes remaining with PInf 0.0000000e+00 265s
5904 PPushes remaining with PInf 0.0000000e+00 270s
2222 PPushes remaining with PInf 0.0000000e+00 275s
445 PPushes remaining with PInf 0.0000000e+00 281s
0 PPushes remaining with PInf 0.0000000e+00 283s
Push phase complete: Pinf 0.0000000e+00, Dinf 8.6769036e-11 283s
Root simplex log...
Iteration Objective Primal Inf. Dual Inf. Time
177097 2.2038385e+04 0.000000e+00 0.000000e+00 283s
Concurrent spin time: 0.01s
Solved with barrier
177097 2.2038385e+04 0.000000e+00 0.000000e+00 283s
Root relaxation: objective 2.203838e+04, 177097 iterations, 260.47 seconds (138.74 work units)
Nodes | Current Node | Objective Bounds | Work
Expl Unexpl | Obj Depth IntInf | Incumbent BestBd Gap | It/Node Time
0 0 22038.3847 0 223821 27025.0000 22038.3847 18.5% - 1317s
H 0 0 23804.000000 22038.3847 7.42% - 1972s
0 0 22038.3847 0 223690 23804.0000 22038.3847 7.42% - 1972s
H 0 0 23788.000000 22039.1204 7.35% - 1976s
H 0 0 23748.000000 22040.9410 7.19% - 4380s
0 0 22040.9410 0 220411 23748.0000 22040.9410 7.19% - 4380s
0 0 22041.7996 0 220356 23748.0000 22041.7996 7.18% - 4390s
Cutting planes:
Zero half: 322
Explored 1 nodes (423613 simplex iterations) in 5401.20 seconds (3313.12 work units)
Thread count was 6 (of 160 available processors)
Solution count 4: 23748 23788 23804 27025
Time limit reached
Best objective 2.374800000000e+04, best bound 2.204200000000e+04, gap 7.1838%
User-callback calls 254955, time in user-callback 693.13 sec
-
Hi Konstantin,
Can I suggest a couple of things to help make this easier to debug:
i) add timestamps to your custom logging
ii) additionally add your logging to the Gurobi logfile using the Model.message function
The log indicates “time in user-callback 693.13 sec” but I'm a little skeptical of this number (and wondering if we have a bug in time keeping). A healthy solve will log lines every 5s (or whatever value is given by DisplayInterval), and there are several instances where there are large gaps in the log, which to me look like they correspond to your ALNS heuristic running.
- Riley
0
サインインしてコメントを残してください。
コメント
1件のコメント