d-krupke / CP-SAT-Log-Analyzer

A webapp that visualizes and annotates your ortools' CP-SAT logs. Partially inspired by gurobi-logtools.
https://cpsat-log-analyzer.streamlit.app/
MIT License
32 stars 1 forks source link

Parser errors when `num_workers` parameter is set #6

Closed leonlan closed 3 months ago

leonlan commented 3 months ago

Problem

Logs from solver runs in which the num_workers parameter is set cannot be parsed.

Example code ```python # Example from https://d-krupke.github.io/cpsat-primer/04_modelling.html from ortools.sat.python import cp_model # Weighted, directed graph as instance # (source, destination) -> cost dgraph = { (0, 1): 13, (1, 0): 17, (1, 2): 16, (2, 1): 19, (0, 2): 22, (2, 0): 14, (3, 0): 15, (3, 1): 28, (3, 2): 25, (0, 3): 24, (1, 3): 11, (2, 3): 27, } model = cp_model.CpModel() # Variables: Binary decision variables for the edges edge_vars = {(u, v): model.NewBoolVar(f"e_{u}_{v}") for (u, v) in dgraph.keys()} # Constraints: Add Circuit constraint # We need to tell CP-SAT which variable corresponds to which edge. # This is done by passing a list of tuples (u,v,var) to AddCircuit. circuit = [ (u, v, var) for (u, v), var in edge_vars.items() # (source, destination, variable) ] model.AddCircuit(circuit) # Objective: minimize the total cost of edges obj = sum(dgraph[(u, v)] * x for (u, v), x in edge_vars.items()) model.Minimize(obj) # Solve solver = cp_model.CpSolver() solver.parameters.num_workers = 2 # solver.parameters.num_search_workers = 1 solver.parameters.log_search_progress = True solver.log_callback = print # (str)->None status = solver.Solve(model) assert status in (cp_model.OPTIMAL, cp_model.FEASIBLE) tour = [(u, v) for (u, v), x in edge_vars.items() if solver.Value(x)] print("Tour:", tour) ```
Example log: ``` Starting CP-SAT solver v9.10.4067 Parameters: log_search_progress: true num_workers: 2 Initial optimization model '': (model_fingerprint: 0xc8df407b243296f5) #Variables: 12 (#bools: 12 in objective) - 12 Booleans in [0,1] #kCircuit: 1 Starting presolve at 0.00s 3.77e-05s 0.00e+00d [DetectDominanceRelations] 6.72e-04s 0.00e+00d [PresolveToFixPoint] #num_loops=2 #num_dual_strengthening=1 6.19e-06s 0.00e+00d [ExtractEncodingFromLinear] 3.11e-04s 1.42e-05d [Probe] #probed=24 #new_binary_clauses=6 8.63e-06s 0.00e+00d [MaxClique] 2.76e-05s 0.00e+00d [DetectDominanceRelations] 5.42e-04s 0.00e+00d [PresolveToFixPoint] #num_loops=1 #num_dual_strengthening=1 4.71e-06s 0.00e+00d [ProcessAtMostOneAndLinear] 7.22e-05s 0.00e+00d [DetectDuplicateConstraints] 2.00e-06s 0.00e+00d [DetectDominatedLinearConstraints] 1.37e-06s 0.00e+00d [DetectDifferentVariables] 2.23e-06s 0.00e+00d [ProcessSetPPC] 2.36e-06s 0.00e+00d [FindAlmostIdenticalLinearConstraints] 4.16e-06s 0.00e+00d [FindBigAtMostOneAndLinearOverlap] 2.70e-06s 1.20e-07d [FindBigVerticalLinearOverlap] 1.62e-06s 0.00e+00d [FindBigHorizontalLinearOverlap] 2.15e-06s 0.00e+00d [MergeClauses] 2.50e-05s 0.00e+00d [DetectDominanceRelations] 9.11e-05s 0.00e+00d [PresolveToFixPoint] #num_loops=1 #num_dual_strengthening=1 2.78e-05s 0.00e+00d [ExpandObjective] Presolve summary: - 0 affine relations were detected. - rule 'TODO dual: only one blocking constraint?' was applied 36 times. - rule 'presolve: 0 unused variables removed.' was applied 1 time. - rule 'presolve: iteration' was applied 1 time. Presolved optimization model '': (model_fingerprint: 0x6ab67e65d25f3b4d) #Variables: 12 (#bools: 12 in objective) - 12 Booleans in [0,1] #kCircuit: 1 Preloading model. #Bound 0.01s best:inf next:[0,231] initial_domain #Model 0.01s var:12/12 constraints:1/1 Starting search at 0.01s with 2 workers. 1 full problem subsolver: [default_lp] 11 incomplete subsolvers: [feasibility_pump, graph_arc_lns, graph_cst_lns, graph_dec_lns, graph_var_lns, rins/rens, rnd_cst_lns, rnd_var_lns, routing_path_lns, routing_random_lns, violation_ls] 3 helper subsolvers: [neighborhood_helper, synchronization_agent, update_gap_integral] #Bound 0.02s best:inf next:[63,231] default_lp #1 0.02s best:63 next:[] default_lp (fixed_bools=1/13) #Done 0.02s default_lp Task timing n [ min, max] avg dev time n [ min, max] avg dev dtime 'default_lp': 1 [ 7.03ms, 7.03ms] 7.03ms 0.00ns 7.03ms 1 [ 2.97us, 2.97us] 2.97us 0.00ns 2.97us 'feasibility_pump': 2 [294.74us, 323.73us] 309.23us 14.49us 618.46us 1 [ 7.05us, 7.05us] 7.05us 0.00ns 7.05us 'graph_arc_lns': 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 'graph_cst_lns': 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 'graph_dec_lns': 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 'graph_var_lns': 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 'rins/rens': 1 [331.75us, 331.75us] 331.75us 0.00ns 331.75us 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 'rnd_cst_lns': 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 'rnd_var_lns': 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 'routing_path_lns': 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 'routing_random_lns': 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 'violation_ls': 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns 0 [ 0.00ns, 0.00ns] 0.00ns 0.00ns 0.00ns Search stats Bools Conflicts Branches Restarts BoolPropag IntegerPropag 'default_lp': 13 0 26 25 71 98 SAT stats ClassicMinim LitRemoved LitLearned LitForgotten Subsumed MClauses MDecisions MLitTrue MSubsumed MLitRemoved MReused 'default_lp': 0 0 0 0 0 0 0 0 0 0 0 Lp stats Component Iterations AddedCuts OPTIMAL DUAL_F. DUAL_U. 'default_lp': 1 7 0 5 0 0 Lp dimension Final dimension of first component 'default_lp': 8 rows, 12 columns, 24 entries with magnitude in [1.000000e+00, 1.000000e+00] Lp debug CutPropag CutEqPropag Adjust Overflow Bad BadScaling 'default_lp': 0 0 4 0 0 0 Lp pool Constraints Updates Simplif Merged Shortened Split Strenghtened Cuts/Call 'default_lp': 8 0 0 8 0 0 0 0/0 LNS stats Improv/Calls Closed Difficulty TimeLimit 'graph_arc_lns': 0/0 0% 0.50 0.10 'graph_cst_lns': 0/0 0% 0.50 0.10 'graph_dec_lns': 0/0 0% 0.50 0.10 'graph_var_lns': 0/0 0% 0.50 0.10 'rins/rens': 0/0 0% 0.50 0.10 'rnd_cst_lns': 0/0 0% 0.50 0.10 'rnd_var_lns': 0/0 0% 0.50 0.10 'routing_path_lns': 0/0 0% 0.50 0.10 'routing_random_lns': 0/0 0% 0.50 0.10 LS stats Batches Restarts LinMoves GenMoves CompoundMoves WeightUpdates 'violation_ls': 0 0 0 0 0 0 Solutions (1) Num Rank 'default_lp': 1 [1,1] Objective bounds Num 'default_lp': 1 'initial_domain': 1 Solution repositories Added Queried Ignored Synchro 'feasible solutions': 1 0 0 1 'lp solutions': 0 0 0 0 'pump': 1 0 CpSolverResponse summary: status: OPTIMAL objective: 63 best_bound: 63 integers: 13 booleans: 13 conflicts: 0 branches: 26 propagations: 71 integer_propagations: 98 restarts: 25 lp_iterations: 7 walltime: 0.0252102 usertime: 0.0252104 deterministic_time: 2.4303e-05 gap_integral: 5.13657e-05 solution_fingerprint: 0xabc7fcb3d5a11d39 Tour: [(0, 1), (2, 0), (3, 2), (1, 3)] ```

Submitting this log file to CP-SAT-Log-Analyzer's streamlit interface gives the following error:

File "/home/adminuser/venv/lib/python3.9/site-packages/streamlit/runtime/scriptrunner/script_runner.py", line 600, in _run_script
    exec(code, module.__dict__)
File "/mount/src/cp-sat-log-analyzer/app.py", line 34, in <module>
    show_overview(parser)
File "/mount/src/cp-sat-log-analyzer/_app/overview.py", line 44, in show_overview
    value=solver_block.get_number_of_workers(),
File "/mount/src/cp-sat-log-analyzer/cpsat_log_parser/blocks/solver.py", line 59, in get_number_of_workers
    raise ValueError("No number of workers found")

Investigation

CP-SAT-Log-Analyzer checks for two things:

https://github.com/d-krupke/CP-SAT-Log-Analyzer/blob/46a80abc58dc207b8c88f4f80a304b0dba2dc02e/cpsat_log_parser/blocks/solver.py#L51-L59

Turns out, I'm setting num_workers parameter instead of num_search_workers.

The parameter file from Google OR-Tools says that num_search_workers is deprecated in favor of num_workers:

https://github.com/google/or-tools/blob/43e400c4f2749268d6a53d39be8f019906fd19c9/ortools/sat/sat_parameters.proto#L560-L568

Proposed solution

Since num_search_workers is still supported as fallback whenever num_workers is not set, I propose adding another if statement like this:

def get_number_of_workers(self) -> int:
    # the line looks like this: "Setting number of workers to 24"
    for line in self.lines:
        if line.startswith("Setting number of workers to"):
            return int(line.strip().split(" ")[-1])

    # If `num_workers` is set, the number of workers is not shown in the log.
    if "num_workers" in self.get_parameters():
        return int(self.get_parameters()["num_workers"])

    # `num_search_workers` is deprecated in favor `num_workers`, but if the
    # latter is not set, `num_search_workers` is still used.
    if "num_search_workers" in self.get_parameters():
        return int(self.get_parameters()["num_search_workers"])

    raise ValueError("No number of workers found")
d-krupke commented 3 months ago

Hey Leon,

Thanks for notifying me about this problem and proposing a solution. Your proposed solution is perfect, I copied it and the application should soon update itself automatically.

Best, Dominik