google / or-tools

Google's Operations Research tools:
https://developers.google.com/optimization/
Apache License 2.0
11.19k stars 2.12k forks source link

The process never end after I call CpSolver.solve #3445

Closed cechjin closed 2 years ago

cechjin commented 2 years ago

Version: 9.4.1874. Language: Java Solver: CP-SAT OS: Mac M1Pro & Linux-x86

My CPU occupation rate is always at 100% after I call CpSolverStatus status = CpSolver.solve(); and it seems that the solving process never end.

Hope the log file useful. cplog.txt

lperron commented 2 years ago

1) this is not a 'bug' of the solver. Optimization problems are NP-Hard and can take a lot of time to solve 2) you did not send the log of the solve, but the text file of the model (which is useful) 3) you should always have a time limit. Parameter max_time_in_second. 4) to enable the log, you need to set the parameter log_search_progress to true. 5) it works better with multiple workers. Here is my log with 16 workers

Parameters: max_time_in_seconds: 10 log_search_progress: true num_search_workers: 16

Initial optimization model '':
#Variables: 93 (#ints:1 in objective)
  - 92 in [0,57]
  - 1 constants in {1} 
#kAllDiff: 46
#kInterval: 31
#kLinMax: 30
#kLinear2: 49
#kNoOverlap: 1 (#intervals: 31)

Starting presolve at 0.00s
[ExtractEncodingFromLinear] #potential_supersets=0 #potential_subsets=0 #at_most_one_encodings=0 #exactly_one_encodings=0 #unique_terms=0 #multiple_terms=0 #literals=0 time=4e-06s
[Probing] deterministic_time: 0 (limit: 1) wall_time: 6e-06 (0/0)
[DetectDuplicateConstraints] #duplicates=0 #without_enforcements=0 time=0.000161s
[DetectDominatedLinearConstraints] #relevant_constraints=18 #work_done=108 #num_inclusions=0 #num_redundant=0 time=4.4e-05s
[DetectOverlappingColumns] #processed_columns=0 #work_done=0 #nz_reduction=0 time=7e-06s
[ProcessSetPPC] #relevant_constraints=0 #num_inclusions=0 work=0 time=7e-06s
[Probing] deterministic_time: 0 (limit: 1) wall_time: 1e-06 (0/0)
[DetectDuplicateConstraints] #duplicates=0 #without_enforcements=0 time=0.000157s
[DetectDominatedLinearConstraints] #relevant_constraints=18 #work_done=108 #num_inclusions=0 #num_redundant=0 time=4.2e-05s
[DetectOverlappingColumns] #processed_columns=0 #work_done=0 #nz_reduction=0 time=6e-06s
[ProcessSetPPC] #relevant_constraints=0 #num_inclusions=0 work=0 time=2e-06s
[Probing] deterministic_time: 0 (limit: 1) wall_time: 1e-06 (0/0)
[DetectDuplicateConstraints] #duplicates=0 #without_enforcements=0 time=0.000163s
[DetectDominatedLinearConstraints] #relevant_constraints=18 #work_done=108 #num_inclusions=0 #num_redundant=0 time=3.6e-05s
[DetectOverlappingColumns] #processed_columns=0 #work_done=0 #nz_reduction=0 time=6e-06s
[ProcessSetPPC] #relevant_constraints=0 #num_inclusions=0 work=0 time=1e-06s

Presolve summary:
  - 31 affine relations were detected.
  - rule 'TODO dual: only one blocking constraint?' was applied 27 times.
  - rule 'TODO dual: only one unspecified blocking constraint?' was applied 558 times.
  - rule 'affine: new relation' was applied 31 times.
  - rule 'all_diff: only one variable' was applied 46 times.
  - rule 'all_diff: propagated fixed expressions' was applied 736 times.
  - rule 'all_diff: removed fixed variables' was applied 46 times.
  - rule 'lin_max: target domain reduced' was applied 45 times.
  - rule 'linear: reduced variable domains' was applied 51 times.
  - rule 'linear: remapped using affine relations' was applied 111 times.
  - rule 'linear: simplified rhs' was applied 32 times.
  - rule 'presolve: 1 unused variables removed.' was applied 1 time.
  - rule 'presolve: iteration' was applied 3 times.

Presolved optimization model '':
#Variables: 61 (#ints:1 in objective)
  - 3 in [0,1][4,8][11,15][18,22][25,29][32,36][39,40]
  - 2 in [0,1][4,8][11,15][18,22][25,29][32,36][39,43][46]
  - 2 in [0,1][4,8][11,15][18,22][25,29][32,36][39,43][46,47]
  - 3 in [0,1][4,8][11,15][18,22][25,29][32,36][39,43][46,48]
  - 12 in [0,1][4,8][11,15][18,22][25,29][32,36][39,43][46,50]
  - 5 in [0,1][4,8][11,15][18,22][25,29][32,36][39,43][46,50][53,55]
  - 5 in [0,1][4,8][11,15][18,22][25,29][32,36][39,43][46,50][53,56]
  - 8 in [0,1][4,8][11,15][18,22][25,29][32,36][39,43][46,50][53,57]
  - 2 in [2][4,9][11,16][18,23][25,30][32,37][39,44][46,51][54,57]
  - 2 in [4,8][11,15][18,22][25,29][32,36][39,43][46,48]
  - 1 in [5,9][12,16][19,23][26,30][33,37][40,44][47,51][54,57]
  - 1 in [5,57]
  - 3 in [7,8][11,15][18,22][25,29][32,36][39,43][46,50][53,57]
  - 1 in [11,15][18,22][25,29][32,36][39,43][46,50][53,55]
  - 1 in [12,15][18,22][25,29][32,36][39,43][46,50][53,56]
  - 1 in [12,16][18,23][25,30][32,37][39,44][46,51][53,56]
  - 1 in [13,16][19,23][26,30][33,37][40,44][47,51][54,57]
  - 2 in [15][18,22][25,29][32,36][39,43][46,50][53,55]
  - 1 in [16,20][23,27][30,34][37,41][44,48][51,55]
  - 1 in [16,57]
  - 1 in [18,22][25,29][32,36][39,43][46,50][53,56]
  - 1 in [19,23][25,30][32,37][39,44][46,51][53,57]
  - 1 in [19,23][26,30][33,37][40,44][47,51][54,57]
  - 1 in [19,57]
#kInterval: 31
#kLinMax: 30
#kLinear2: 18
#kNoOverlap: 1 (#intervals: 31)

Preloading model.
#Bound   0.01s best:inf   next:[19,57]    initial_domain
#Model   0.01s var:61/61 constraints:80/80

Starting Search at 0.01s with 16 workers.
10 full subsolvers: [default_lp, fixed, no_lp, max_lp, reduced_costs, pseudo_costs, quick_restart, quick_restart_no_lp, lb_tree_search, probing]
Interleaved subsolvers: [feasibility_pump, rnd_var_lns_default, rnd_cst_lns_default, graph_var_lns_default, graph_cst_lns_default, scheduling_random_intervals_lns_default, scheduling_random_precedences_lns_default, scheduling_time_window_lns_default, rins_lns_default, rens_lns_default]
#Bound   0.01s best:inf   next:[20,57]    probing
#Bound   0.02s best:inf   next:[33,57]    max_lp
#Bound   0.04s best:inf   next:[34,57]    reduced_costs
#Bound   0.04s best:inf   next:[35,57]    reduced_costs
#Bound   0.04s best:inf   next:[36,57]    reduced_costs
#Bound   0.05s best:inf   next:[37,57]    reduced_costs
#Bound   0.05s best:inf   next:[38,57]    reduced_costs
#Bound   0.06s best:inf   next:[39,57]    reduced_costs
#Bound   0.06s best:inf   next:[40,57]    reduced_costs
#Bound   0.07s best:inf   next:[41,57]    reduced_costs
#Bound   0.08s best:inf   next:[42,57]    reduced_costs
#Bound   0.08s best:inf   next:[43,57]    reduced_costs
#Bound   0.09s best:inf   next:[44,57]    reduced_costs
#Bound   0.09s best:inf   next:[45,57]    reduced_costs
#Bound   0.10s best:inf   next:[46,57]    reduced_costs
#Bound   0.11s best:inf   next:[47,57]    reduced_costs
#Bound   0.11s best:inf   next:[48,57]    reduced_costs
#Bound   0.12s best:inf   next:[49,57]    reduced_costs
#Bound   0.13s best:inf   next:[50,57]    reduced_costs
#Bound   0.13s best:inf   next:[51,57]    reduced_costs
#Bound   0.14s best:inf   next:[52,57]    reduced_costs
#Bound   0.14s best:inf   next:[53,57]    reduced_costs
#Bound   0.15s best:inf   next:[54,57]    reduced_costs
#Bound   0.16s best:inf   next:[55,57]    reduced_costs
#Bound   0.16s best:inf   next:[56,57]    reduced_costs
#Bound   0.17s best:inf   next:[57,57]    reduced_costs

Sub-solver search statistics:
  'max_lp':
     LP statistics:
       final dimension: 56 rows, 147 columns, 305 entries with magnitude in [6.375767e-03, 1.000000e+00]
       total number of simplex iterations: 31843
       num solves: 
         - #OPTIMAL: 48732
         - #DUAL_FEASIBLE: 107
       managed constraints: 1255
       merged constraints: 1284
       shortened constraints: 80
       coefficient strenghtenings: 103
       num simplifications: 265
       total cuts added: 1088 (out of 170929 calls)
         - 'CG': 78
         - 'IB': 1
         - 'LinMax': 140
         - 'MIR_1': 49
         - 'MIR_2': 36
         - 'MIR_3': 9
         - 'MIR_3_F': 1
         - 'MIR_4': 2
         - 'MIR_4_F': 1
         - 'MIR_5': 3
         - 'MIR_6': 1
         - 'NoOverlapCompletionTimeExhaustiveMirror_weighted': 95
         - 'NoOverlapCompletionTimeExhaustiveMirror_weighted_lifted': 118
         - 'NoOverlapCompletionTimeExhaustive_weighted': 236
         - 'NoOverlapCompletionTimeExhaustive_weighted_lifted': 7
         - 'NoOverlapCompletionTimeQueyrane': 59
         - 'NoOverlapCompletionTimeQueyraneMirror': 60
         - 'NoOverlapCompletionTimeQueyraneMirror_lifted': 41
         - 'NoOverlapCompletionTimeQueyrane_lifted': 1
         - 'NoOverlapDisjunctionOnEnd': 40
         - 'NoOverlapDisjunctionOnStart': 65
         - 'ZERO_HALF': 45

  'reduced_costs':
     LP statistics:
       final dimension: 108 rows, 147 columns, 515 entries with magnitude in [1.666667e-03, 1.000000e+00]
       total number of simplex iterations: 46188
       num solves: 
         - #OPTIMAL: 44553
         - #DUAL_UNBOUNDED: 4
         - #DUAL_FEASIBLE: 72
       managed constraints: 1490
       merged constraints: 982
       shortened constraints: 99
       coefficient strenghtenings: 132
       num simplifications: 430
       total cuts added: 1333 (out of 132410 calls)
         - 'CG': 73
         - 'IB': 1
         - 'LinMax': 81
         - 'MIR_1': 26
         - 'MIR_2': 36
         - 'MIR_3': 13
         - 'MIR_3_F': 2
         - 'MIR_4': 9
         - 'MIR_4_F': 3
         - 'MIR_5': 4
         - 'MIR_6': 2
         - 'NoOverlapCompletionTimeExhaustiveMirror_weighted': 224
         - 'NoOverlapCompletionTimeExhaustiveMirror_weighted_lifted': 112
         - 'NoOverlapCompletionTimeExhaustive_weighted': 334
         - 'NoOverlapCompletionTimeExhaustive_weighted_lifted': 15
         - 'NoOverlapCompletionTimeQueyrane': 78
         - 'NoOverlapCompletionTimeQueyraneMirror': 105
         - 'NoOverlapCompletionTimeQueyraneMirror_lifted': 40
         - 'NoOverlapCompletionTimeQueyrane_lifted': 2
         - 'NoOverlapDisjunctionOnEnd': 52
         - 'NoOverlapDisjunctionOnStart': 61
         - 'ZERO_HALF': 59
         - 'ZERO_HALF_F': 1

  'pseudo_costs':
     LP statistics:
       final dimension: 109 rows, 147 columns, 570 entries with magnitude in [4.082483e-02, 1.000000e+00]
       total number of simplex iterations: 38997
       num solves: 
         - #OPTIMAL: 48539
         - #DUAL_FEASIBLE: 42
       managed constraints: 1446
       merged constraints: 1163
       shortened constraints: 74
       coefficient strenghtenings: 137
       num simplifications: 387
       total cuts added: 1280 (out of 158572 calls)
         - 'CG': 64
         - 'IB': 1
         - 'LinMax': 111
         - 'MIR_1': 25
         - 'MIR_2': 42
         - 'MIR_3': 22
         - 'MIR_3_F': 3
         - 'MIR_4': 6
         - 'MIR_4_F': 2
         - 'MIR_5': 5
         - 'MIR_6': 3
         - 'NoOverlapCompletionTimeExhaustiveMirror_weighted': 136
         - 'NoOverlapCompletionTimeExhaustiveMirror_weighted_lifted': 162
         - 'NoOverlapCompletionTimeExhaustive_weighted': 299
         - 'NoOverlapCompletionTimeExhaustive_weighted_lifted': 12
         - 'NoOverlapCompletionTimeQueyrane': 77
         - 'NoOverlapCompletionTimeQueyraneMirror': 87
         - 'NoOverlapCompletionTimeQueyraneMirror_lifted': 49
         - 'NoOverlapCompletionTimeQueyrane_lifted': 2
         - 'NoOverlapDisjunctionOnEnd': 60
         - 'NoOverlapDisjunctionOnStart': 70
         - 'ZERO_HALF': 41
         - 'ZERO_HALF_F': 1

  'lb_tree_search':
     LP statistics:
       final dimension: 45 rows, 147 columns, 242 entries with magnitude in [1.324532e-01, 1.000000e+00]
       total number of simplex iterations: 41401
       num solves: 
         - #OPTIMAL: 58518
         - #DUAL_UNBOUNDED: 4
         - #DUAL_FEASIBLE: 1
       managed constraints: 304
       merged constraints: 211
       shortened constraints: 30
       coefficient strenghtenings: 8
       num simplifications: 174
       total cuts added: 138 (out of 180333 calls)
         - 'CG': 13
         - 'LinMax': 16
         - 'MIR_1': 4
         - 'MIR_2': 6
         - 'MIR_3': 7
         - 'MIR_3_F': 4
         - 'MIR_4': 4
         - 'MIR_4_F': 4
         - 'MIR_5': 1
         - 'NoOverlapCompletionTimeExhaustiveMirror_weighted': 15
         - 'NoOverlapCompletionTimeExhaustive_weighted': 6
         - 'NoOverlapCompletionTimeExhaustive_weighted_lifted': 12
         - 'NoOverlapCompletionTimeQueyrane': 4
         - 'NoOverlapCompletionTimeQueyraneMirror': 9
         - 'NoOverlapCompletionTimeQueyrane_lifted': 2
         - 'NoOverlapDisjunctionOnEnd': 7
         - 'NoOverlapDisjunctionOnStart': 8
         - 'ZERO_HALF': 15
         - 'ZERO_HALF_F': 1

Objective bounds found per subsolver:
  'initial_domain': 1
  'max_lp': 1
  'probing': 1
  'reduced_costs': 24

Improving variable bounds shared per subsolver:
  'max_lp': 1
  'no_lp': 8
  'probing': 75
  'quick_restart': 3
  'reduced_costs': 24

CpSolverResponse summary:
status: UNKNOWN
objective: 57
best_bound: 57
booleans: 762
conflicts: 15174
branches: 18182
propagations: 673150
integer_propagations: 559008
restarts: 45
lp_iterations: 31843
walltime: 10.0265
usertime: 10.0265
deterministic_time: 12.2729
gap_integral: 0.00593943