From aac6e2f1c49cfb1437b129f76f8edbb017eccda5 Mon Sep 17 00:00:00 2001 From: jasherma Date: Sat, 16 Mar 2024 20:12:48 -0400 Subject: [PATCH 01/14] Standardize PyROS subordinate solver calls --- pyomo/contrib/pyros/master_problem_methods.py | 96 ++++++------------- .../pyros/separation_problem_methods.py | 45 +++------ pyomo/contrib/pyros/util.py | 78 +++++++++++++++ 3 files changed, 120 insertions(+), 99 deletions(-) diff --git a/pyomo/contrib/pyros/master_problem_methods.py b/pyomo/contrib/pyros/master_problem_methods.py index 8b9e85b90e9..2af38c1d582 100644 --- a/pyomo/contrib/pyros/master_problem_methods.py +++ b/pyomo/contrib/pyros/master_problem_methods.py @@ -27,6 +27,7 @@ from pyomo.core.expr import value from pyomo.core.base.set_types import NonNegativeIntegers, NonNegativeReals from pyomo.contrib.pyros.util import ( + call_solver, selective_clone, ObjectiveType, pyrosTerminationCondition, @@ -239,31 +240,18 @@ def solve_master_feasibility_problem(model_data, config): else: solver = config.local_solver - timer = TicTocTimer() - orig_setting, custom_setting_present = adjust_solver_time_settings( - model_data.timing, solver, config - ) - model_data.timing.start_timer("main.master_feasibility") - timer.tic(msg=None) - try: - results = solver.solve(model, tee=config.tee, load_solutions=False) - except ApplicationError: - # account for possible external subsolver errors - # (such as segmentation faults, function evaluation - # errors, etc.) - config.progress_logger.error( + results = call_solver( + model=model, + solver=solver, + config=config, + timing_obj=model_data.timing, + timer_name="main.master_feasibility", + err_msg=( f"Optimizer {repr(solver)} encountered exception " "attempting to solve master feasibility problem in iteration " f"{model_data.iteration}." - ) - raise - else: - setattr(results.solver, TIC_TOC_SOLVE_TIME_ATTR, timer.toc(msg=None)) - model_data.timing.stop_timer("main.master_feasibility") - finally: - revert_solver_max_time_adjustment( - solver, orig_setting, custom_setting_present, config - ) + ), + ) feasible_terminations = { tc.optimal, @@ -482,28 +470,18 @@ def minimize_dr_vars(model_data, config): config.progress_logger.debug(f" Initial DR norm: {value(polishing_obj)}") # === Solve the polishing model - timer = TicTocTimer() - orig_setting, custom_setting_present = adjust_solver_time_settings( - model_data.timing, solver, config - ) - model_data.timing.start_timer("main.dr_polishing") - timer.tic(msg=None) - try: - results = solver.solve(polishing_model, tee=config.tee, load_solutions=False) - except ApplicationError: - config.progress_logger.error( + results = call_solver( + model=polishing_model, + solver=solver, + config=config, + timing_obj=model_data.timing, + timer_name="main.dr_polishing", + err_msg=( f"Optimizer {repr(solver)} encountered an exception " "attempting to solve decision rule polishing problem " f"in iteration {model_data.iteration}" - ) - raise - else: - setattr(results.solver, TIC_TOC_SOLVE_TIME_ATTR, timer.toc(msg=None)) - model_data.timing.stop_timer("main.dr_polishing") - finally: - revert_solver_max_time_adjustment( - solver, orig_setting, custom_setting_present, config - ) + ), + ) # interested in the time and termination status for debugging # purposes @@ -726,7 +704,6 @@ def solver_call_master(model_data, config, solver, solve_data): solve_mode = "global" if config.solve_master_globally else "local" config.progress_logger.debug("Solving master problem") - timer = TicTocTimer() for idx, opt in enumerate(solvers): if idx > 0: config.progress_logger.warning( @@ -734,35 +711,18 @@ def solver_call_master(model_data, config, solver, solve_data): f"(solver {idx + 1} of {len(solvers)}) for " f"master problem of iteration {model_data.iteration}." ) - orig_setting, custom_setting_present = adjust_solver_time_settings( - model_data.timing, opt, config - ) - model_data.timing.start_timer("main.master") - timer.tic(msg=None) - try: - results = opt.solve( - nlp_model, - tee=config.tee, - load_solutions=False, - symbolic_solver_labels=True, - ) - except ApplicationError: - # account for possible external subsolver errors - # (such as segmentation faults, function evaluation - # errors, etc.) - config.progress_logger.error( + results = call_solver( + model=nlp_model, + solver=opt, + config=config, + timing_obj=model_data.timing, + timer_name="main.master", + err_msg=( f"Optimizer {repr(opt)} ({idx + 1} of {len(solvers)}) " "encountered exception attempting to " f"solve master problem in iteration {model_data.iteration}" - ) - raise - else: - setattr(results.solver, TIC_TOC_SOLVE_TIME_ATTR, timer.toc(msg=None)) - model_data.timing.stop_timer("main.master") - finally: - revert_solver_max_time_adjustment( - solver, orig_setting, custom_setting_present, config - ) + ), + ) optimal_termination = check_optimal_termination(results) infeasible = results.solver.termination_condition == tc.infeasible diff --git a/pyomo/contrib/pyros/separation_problem_methods.py b/pyomo/contrib/pyros/separation_problem_methods.py index b5939ff5b19..18d0925bab0 100644 --- a/pyomo/contrib/pyros/separation_problem_methods.py +++ b/pyomo/contrib/pyros/separation_problem_methods.py @@ -18,7 +18,6 @@ from pyomo.core.base import Var, Param from pyomo.common.collections import ComponentSet, ComponentMap from pyomo.common.dependencies import numpy as np -from pyomo.contrib.pyros.util import ObjectiveType, get_time_from_solver from pyomo.contrib.pyros.solve_data import ( DiscreteSeparationSolveCallResults, SeparationSolveCallResults, @@ -37,9 +36,11 @@ from pyomo.contrib.pyros.util import ABS_CON_CHECK_FEAS_TOL from pyomo.common.timing import TicTocTimer from pyomo.contrib.pyros.util import ( - TIC_TOC_SOLVE_TIME_ATTR, adjust_solver_time_settings, + call_solver, + ObjectiveType, revert_solver_max_time_adjustment, + TIC_TOC_SOLVE_TIME_ATTR, ) import os from copy import deepcopy @@ -1070,6 +1071,7 @@ def solver_call_separation( separation_obj.activate() + solve_mode_adverb = "globally" if solve_globally else "locally" solve_call_results = SeparationSolveCallResults( solved_globally=solve_globally, time_out=False, @@ -1077,7 +1079,6 @@ def solver_call_separation( found_violation=False, subsolver_error=False, ) - timer = TicTocTimer() for idx, opt in enumerate(solvers): if idx > 0: config.progress_logger.warning( @@ -1086,37 +1087,19 @@ def solver_call_separation( f"separation of performance constraint {con_name_repr} " f"in iteration {model_data.iteration}." ) - orig_setting, custom_setting_present = adjust_solver_time_settings( - model_data.timing, opt, config - ) - model_data.timing.start_timer(f"main.{solve_mode}_separation") - timer.tic(msg=None) - try: - results = opt.solve( - nlp_model, - tee=config.tee, - load_solutions=False, - symbolic_solver_labels=True, - ) - except ApplicationError: - # account for possible external subsolver errors - # (such as segmentation faults, function evaluation - # errors, etc.) - adverb = "globally" if solve_globally else "locally" - config.progress_logger.error( + results = call_solver( + model=nlp_model, + solver=opt, + config=config, + timing_obj=model_data.timing, + timer_name=f"main.{solve_mode}_separation", + err_msg=( f"Optimizer {repr(opt)} ({idx + 1} of {len(solvers)}) " f"encountered exception attempting " - f"to {adverb} solve separation problem for constraint " + f"to {solve_mode_adverb} solve separation problem for constraint " f"{con_name_repr} in iteration {model_data.iteration}." - ) - raise - else: - setattr(results.solver, TIC_TOC_SOLVE_TIME_ATTR, timer.toc(msg=None)) - model_data.timing.stop_timer(f"main.{solve_mode}_separation") - finally: - revert_solver_max_time_adjustment( - opt, orig_setting, custom_setting_present, config - ) + ), + ) # record termination condition for this particular solver solver_status_dict[str(opt)] = results.solver.termination_condition diff --git a/pyomo/contrib/pyros/util.py b/pyomo/contrib/pyros/util.py index a3ab3464aa8..33551115148 100644 --- a/pyomo/contrib/pyros/util.py +++ b/pyomo/contrib/pyros/util.py @@ -16,7 +16,9 @@ import copy from enum import Enum, auto from pyomo.common.collections import ComponentSet, ComponentMap +from pyomo.common.errors import ApplicationError from pyomo.common.modeling import unique_component_name +from pyomo.common.timing import TicTocTimer from pyomo.core.base import ( Constraint, Var, @@ -1731,6 +1733,82 @@ def process_termination_condition_master_problem(config, results): ) +def call_solver(model, solver, config, timing_obj, timer_name, err_msg): + """ + Solve a model with a given optimizer, keeping track of + wall time requirements. + + Parameters + ---------- + model : ConcreteModel + Model of interest. + solver : Pyomo solver type + Subordinate optimizer. + config : ConfigDict + PyROS solver settings. + timing_obj : TimingData + PyROS solver timing data object. + timer_name : str + Name of sub timer under the hierarchical timer contained in + ``timing_obj`` to start/stop for keeping track of solve + time requirements. + err_msg : str + Message to log through ``config.progress_logger.exception()`` + in event an ApplicationError is raised while attempting to + solve the model. + + Returns + ------- + SolverResults + Solve results. Note that ``results.solver`` contains + an additional attribute, named after + ``TIC_TOC_SOLVE_TIME_ATTR``, of which the value is set to the + recorded solver wall time. + + Raises + ------ + ApplicationError + If ApplicationError is raised by the solver. + In this case, `err_msg` is logged through + ``config.progress_logger.exception()`` before + the excception is raised. + """ + tt_timer = TicTocTimer() + + orig_setting, custom_setting_present = adjust_solver_time_settings( + timing_obj, solver, config + ) + timing_obj.start_timer(timer_name) + tt_timer.tic(msg=None) + + try: + results = solver.solve( + model, + tee=config.tee, + load_solutions=False, + symbolic_solver_labels=True, + ) + except ApplicationError: + # account for possible external subsolver errors + # (such as segmentation faults, function evaluation + # errors, etc.) + config.progress_logger.error(err_msg) + raise + else: + setattr( + results.solver, + TIC_TOC_SOLVE_TIME_ATTR, + tt_timer.toc(msg=None, delta=True), + ) + finally: + timing_obj.stop_timer(timer_name) + revert_solver_max_time_adjustment( + solver, orig_setting, custom_setting_present, config + ) + + return results + + class IterationLogRecord: """ PyROS solver iteration log record. From d9f22516d0b79d204462ffb91095b408423de524 Mon Sep 17 00:00:00 2001 From: jasherma Date: Sun, 17 Mar 2024 15:57:18 -0400 Subject: [PATCH 02/14] Account for user settings in subsolver time limit adjustment --- pyomo/contrib/pyros/util.py | 68 +++++++++++++++++++++++++++---------- 1 file changed, 50 insertions(+), 18 deletions(-) diff --git a/pyomo/contrib/pyros/util.py b/pyomo/contrib/pyros/util.py index 33551115148..7d40d357863 100644 --- a/pyomo/contrib/pyros/util.py +++ b/pyomo/contrib/pyros/util.py @@ -232,15 +232,15 @@ def get_main_elapsed_time(timing_data_obj): def adjust_solver_time_settings(timing_data_obj, solver, config): """ - Adjust solver max time setting based on current PyROS elapsed - time. + Adjust maximum time allowed for subordinate solver, based + on total PyROS solver elapsed time up to this point. Parameters ---------- timing_data_obj : Bunch PyROS timekeeper. solver : solver type - Solver for which to adjust the max time setting. + Subordinate solver for which to adjust the max time setting. config : ConfigDict PyROS solver config. @@ -262,26 +262,40 @@ def adjust_solver_time_settings(timing_data_obj, solver, config): ---- (1) Adjustment only supported for GAMS, BARON, and IPOPT interfaces. This routine can be generalized to other solvers - after a generic interface to the time limit setting + after a generic Pyomo interface to the time limit setting is introduced. - (2) For IPOPT, and probably also BARON, the CPU time limit - rather than the wallclock time limit, is adjusted, as - no interface to wallclock limit available. - For this reason, extra 30s is added to time remaining - for subsolver time limit. - (The extra 30s is large enough to ensure solver - elapsed time is not beneath elapsed time - user time limit, - but not so large as to overshoot the user-specified time limit - by an inordinate margin.) + (2) For IPOPT and BARON, the CPU time limit, + rather than the wallclock time limit, may be adjusted, + as there may be no means by which to specify the wall time + limit explicitly. + (3) For GAMS, we adjust the time limit through the GAMS Reslim + option. However, this may be overriden by any user + specifications included in a GAMS optfile, which may be + difficult to track down. + (3) To ensure the time limit is specified to a strictly + positive value, the time limit is adjusted to a value of + at least 1 second. """ + # in case there is no time remaining: we set time limit + # to a minimum of 1s, as some solvers require a strictly + # positive time limit + time_limit_buffer = 1 + if config.time_limit is not None: time_remaining = config.time_limit - get_main_elapsed_time(timing_data_obj) if isinstance(solver, type(SolverFactory("gams", solver_io="shell"))): original_max_time_setting = solver.options["add_options"] custom_setting_present = "add_options" in solver.options - # adjust GAMS solver time - reslim_str = f"option reslim={max(30, 30 + time_remaining)};" + # note: our time limit will be overriden by any + # time limits specified by the user through a + # GAMS optfile, but tracking down the optfile + # and/or the GAMS subsolver specific option + # is more difficult + reslim_str = ( + "option reslim=" + f"{max(time_limit_buffer, time_remaining)};" + ) if isinstance(solver.options["add_options"], list): solver.options["add_options"].append(reslim_str) else: @@ -291,7 +305,13 @@ def adjust_solver_time_settings(timing_data_obj, solver, config): if isinstance(solver, SolverFactory.get_class("baron")): options_key = "MaxTime" elif isinstance(solver, SolverFactory.get_class("ipopt")): - options_key = "max_cpu_time" + options_key = ( + # IPOPT 3.14.0+ added support for specifying + # wall time limit explicitly; this is preferred + # over CPU time limit + "max_wall_time" if solver.version() >= (3, 14, 0, 0) + else "max_cpu_time" + ) else: options_key = None @@ -299,8 +319,20 @@ def adjust_solver_time_settings(timing_data_obj, solver, config): custom_setting_present = options_key in solver.options original_max_time_setting = solver.options[options_key] - # ensure positive value assigned to avoid application error - solver.options[options_key] = max(30, 30 + time_remaining) + # account for elapsed time remaining and + # original time limit setting. + # if no original time limit is set, then we assume + # there is no time limit, rather than tracking + # down the solver-specific default + orig_max_time = ( + float("inf") + if original_max_time_setting is None + else original_max_time_setting + ) + solver.options[options_key] = min( + max(time_limit_buffer, time_remaining), + orig_max_time, + ) else: custom_setting_present = False original_max_time_setting = None From 2593fce468e4f8095a2c2c35698323155035d2e8 Mon Sep 17 00:00:00 2001 From: jasherma Date: Sun, 17 Mar 2024 18:05:38 -0400 Subject: [PATCH 03/14] Fix test error message string --- pyomo/contrib/pyros/tests/test_grcs.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pyomo/contrib/pyros/tests/test_grcs.py b/pyomo/contrib/pyros/tests/test_grcs.py index c308f0d6990..754ab6678ea 100644 --- a/pyomo/contrib/pyros/tests/test_grcs.py +++ b/pyomo/contrib/pyros/tests/test_grcs.py @@ -4398,8 +4398,8 @@ def test_gams_successful_time_limit(self): results.pyros_termination_condition, pyrosTerminationCondition.robust_optimal, msg=( - f"Returned termination condition with local " - "subsolver {idx + 1} of 2 is not robust_optimal." + "Returned termination condition with local " + f"subsolver {idx + 1} of 2 is not robust_optimal." ), ) From 679dc7ee4620a1d424d055250363e84d24bca86c Mon Sep 17 00:00:00 2001 From: jasherma Date: Sun, 17 Mar 2024 18:38:48 -0400 Subject: [PATCH 04/14] Add support for SCIP time limit adjustment --- pyomo/contrib/pyros/tests/test_grcs.py | 77 +++++++------------------- pyomo/contrib/pyros/util.py | 4 ++ 2 files changed, 24 insertions(+), 57 deletions(-) diff --git a/pyomo/contrib/pyros/tests/test_grcs.py b/pyomo/contrib/pyros/tests/test_grcs.py index 754ab6678ea..92532677a80 100644 --- a/pyomo/contrib/pyros/tests/test_grcs.py +++ b/pyomo/contrib/pyros/tests/test_grcs.py @@ -4345,10 +4345,10 @@ def test_separation_terminate_time_limit(self): and SolverFactory('baron').license_is_valid(), "Global NLP solver is not available and licensed.", ) - def test_gams_successful_time_limit(self): + def test_pyros_subsolver_time_limit_adjustment(self): """ - Test PyROS time limit status returned in event - separation problem times out. + Check that PyROS does not ultimately alter state of + subordinate solver options due to time limit adjustments. """ m = ConcreteModel() m.x1 = Var(initialize=0, bounds=(0, None)) @@ -4367,20 +4367,26 @@ def test_gams_successful_time_limit(self): # Instantiate the PyROS solver pyros_solver = SolverFactory("pyros") - # Define subsolvers utilized in the algorithm - # two GAMS solvers, one of which has reslim set - # (overridden when invoked in PyROS) + # subordinate solvers to test. + # for testing, we pass each as the 'local' solver, + # and the BARON solver without custom options + # as the 'global' solver + baron_no_options = SolverFactory("baron") local_subsolvers = [ SolverFactory("gams:conopt"), SolverFactory("gams:conopt"), SolverFactory("ipopt"), + SolverFactory("ipopt", options={"max_cpu_time": 300}), + SolverFactory("scip"), + SolverFactory("scip", options={"limits/time": 300}), + baron_no_options, + SolverFactory("baron", options={"MaxTime": 300}), ] local_subsolvers[0].options["add_options"] = ["option reslim=100;"] - global_subsolver = SolverFactory("baron") - global_subsolver.options["MaxTime"] = 300 # Call the PyROS solver for idx, opt in enumerate(local_subsolvers): + original_solver_options = opt.options.copy() results = pyros_solver.solve( model=m, first_stage_variables=[m.x1, m.x2], @@ -4388,12 +4394,11 @@ def test_gams_successful_time_limit(self): uncertain_params=[m.u], uncertainty_set=interval, local_solver=opt, - global_solver=global_subsolver, + global_solver=baron_no_options, objective_focus=ObjectiveType.worst_case, solve_master_globally=True, time_limit=100, ) - self.assertEqual( results.pyros_termination_condition, pyrosTerminationCondition.robust_optimal, @@ -4402,54 +4407,12 @@ def test_gams_successful_time_limit(self): f"subsolver {idx + 1} of 2 is not robust_optimal." ), ) - - # check first local subsolver settings - # remain unchanged after PyROS exit - self.assertEqual( - len(list(local_subsolvers[0].options["add_options"])), - 1, - msg=( - f"Local subsolver {local_subsolvers[0]} options 'add_options'" - "were changed by PyROS" - ), - ) - self.assertEqual( - local_subsolvers[0].options["add_options"][0], - "option reslim=100;", - msg=( - f"Local subsolver {local_subsolvers[0]} setting " - "'add_options' was modified " - "by PyROS, but changes were not properly undone" - ), - ) - - # check global subsolver settings unchanged - self.assertEqual( - len(list(global_subsolver.options.keys())), - 1, - msg=(f"Global subsolver {global_subsolver} options were changed by PyROS"), - ) - self.assertEqual( - global_subsolver.options["MaxTime"], - 300, - msg=( - f"Global subsolver {global_subsolver} setting " - "'MaxTime' was modified " - "by PyROS, but changes were not properly undone" - ), - ) - - # check other local subsolvers remain unchanged - for slvr, key in zip(local_subsolvers[1:], ["add_options", "max_cpu_time"]): - # no custom options were added to the `options` - # attribute of the optimizer, so any attribute - # of `options` should be `None` - self.assertIs( - getattr(slvr.options, key, None), - None, + self.assertEqual( + opt.options, + original_solver_options, msg=( - f"Local subsolver {slvr} setting '{key}' was added " - "by PyROS, but not reverted" + f"Options for subordinate solver {opt} were changed " + "by PyROS, and the changes wee not properly reverted." ), ) diff --git a/pyomo/contrib/pyros/util.py b/pyomo/contrib/pyros/util.py index 7d40d357863..bdec2213d43 100644 --- a/pyomo/contrib/pyros/util.py +++ b/pyomo/contrib/pyros/util.py @@ -312,6 +312,8 @@ def adjust_solver_time_settings(timing_data_obj, solver, config): "max_wall_time" if solver.version() >= (3, 14, 0, 0) else "max_cpu_time" ) + elif isinstance(solver, SolverFactory.get_class("scip")): + options_key = "limits/time" else: options_key = None @@ -379,6 +381,8 @@ def revert_solver_max_time_adjustment( options_key = "MaxTime" elif isinstance(solver, SolverFactory.get_class("ipopt")): options_key = "max_cpu_time" + elif isinstance(solver, SolverFactory.get_class("scip")): + options_key = "limits/time" else: options_key = None From fcb28193147e55e18f69128d10060d2b8839ca8b Mon Sep 17 00:00:00 2001 From: jasherma Date: Sun, 17 Mar 2024 18:42:21 -0400 Subject: [PATCH 05/14] Simplify time limit adjustment reversion --- pyomo/contrib/pyros/util.py | 5 ----- 1 file changed, 5 deletions(-) diff --git a/pyomo/contrib/pyros/util.py b/pyomo/contrib/pyros/util.py index bdec2213d43..fa423e37450 100644 --- a/pyomo/contrib/pyros/util.py +++ b/pyomo/contrib/pyros/util.py @@ -397,12 +397,7 @@ def revert_solver_max_time_adjustment( if isinstance(solver, type(SolverFactory("gams", solver_io="shell"))): solver.options[options_key].pop() else: - # remove the max time specification introduced. - # All lines are needed here to completely remove the option - # from access through getattr and dictionary reference. delattr(solver.options, options_key) - if options_key in solver.options.keys(): - del solver.options[options_key] class PreformattedLogger(logging.Logger): From 0c8afa56489f3c32d987b75ab65038538d3e9735 Mon Sep 17 00:00:00 2001 From: jasherma Date: Sun, 17 Mar 2024 18:56:22 -0400 Subject: [PATCH 06/14] Update solver test availability and license check --- pyomo/contrib/pyros/tests/test_grcs.py | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/pyomo/contrib/pyros/tests/test_grcs.py b/pyomo/contrib/pyros/tests/test_grcs.py index 92532677a80..41223b30899 100644 --- a/pyomo/contrib/pyros/tests/test_grcs.py +++ b/pyomo/contrib/pyros/tests/test_grcs.py @@ -4341,9 +4341,11 @@ def test_separation_terminate_time_limit(self): ) @unittest.skipUnless( - SolverFactory('gams').license_is_valid() - and SolverFactory('baron').license_is_valid(), - "Global NLP solver is not available and licensed.", + ipopt_available + and SolverFactory('gams').license_is_valid() + and SolverFactory('baron').license_is_valid() + and SolverFactory("scip").license_is_valid(), + "IPOPT not available or one of GAMS/BARON/SCIP not licensed", ) def test_pyros_subsolver_time_limit_adjustment(self): """ From ec830e6c19600419a3a187c7c63c9f1700bedfcf Mon Sep 17 00:00:00 2001 From: jasherma Date: Sun, 17 Mar 2024 19:05:33 -0400 Subject: [PATCH 07/14] Move PyROS timer start to before argument validation --- pyomo/contrib/pyros/pyros.py | 30 +++++++++++------------------- 1 file changed, 11 insertions(+), 19 deletions(-) diff --git a/pyomo/contrib/pyros/pyros.py b/pyomo/contrib/pyros/pyros.py index 6de42d7299e..c74daf34c5f 100644 --- a/pyomo/contrib/pyros/pyros.py +++ b/pyomo/contrib/pyros/pyros.py @@ -330,32 +330,24 @@ def solve( Summary of PyROS termination outcome. """ - kwds.update( - dict( - first_stage_variables=first_stage_variables, - second_stage_variables=second_stage_variables, - uncertain_params=uncertain_params, - uncertainty_set=uncertainty_set, - local_solver=local_solver, - global_solver=global_solver, - ) - ) - config, state_vars = self._resolve_and_validate_pyros_args(model, **kwds) - - # === Create data containers model_data = ROSolveResults() - model_data.timing = Bunch() - - # === Start timer, run the algorithm model_data.timing = TimingData() with time_code( timing_data_obj=model_data.timing, code_block_name="main", is_main_timer=True, ): - # output intro and disclaimer - self._log_intro(logger=config.progress_logger, level=logging.INFO) - self._log_disclaimer(logger=config.progress_logger, level=logging.INFO) + kwds.update( + dict( + first_stage_variables=first_stage_variables, + second_stage_variables=second_stage_variables, + uncertain_params=uncertain_params, + uncertainty_set=uncertainty_set, + local_solver=local_solver, + global_solver=global_solver, + ) + ) + config, state_vars = self._resolve_and_validate_pyros_args(model, **kwds) self._log_config( logger=config.progress_logger, config=config, From 348a896bb77f2ad2634043647303e325edd1e06f Mon Sep 17 00:00:00 2001 From: jasherma Date: Sun, 17 Mar 2024 19:14:24 -0400 Subject: [PATCH 08/14] Fix typos --- pyomo/contrib/pyros/util.py | 24 ++++++++---------------- 1 file changed, 8 insertions(+), 16 deletions(-) diff --git a/pyomo/contrib/pyros/util.py b/pyomo/contrib/pyros/util.py index fa423e37450..306141e9829 100644 --- a/pyomo/contrib/pyros/util.py +++ b/pyomo/contrib/pyros/util.py @@ -269,7 +269,7 @@ def adjust_solver_time_settings(timing_data_obj, solver, config): as there may be no means by which to specify the wall time limit explicitly. (3) For GAMS, we adjust the time limit through the GAMS Reslim - option. However, this may be overriden by any user + option. However, this may be overridden by any user specifications included in a GAMS optfile, which may be difficult to track down. (3) To ensure the time limit is specified to a strictly @@ -287,15 +287,12 @@ def adjust_solver_time_settings(timing_data_obj, solver, config): original_max_time_setting = solver.options["add_options"] custom_setting_present = "add_options" in solver.options - # note: our time limit will be overriden by any + # note: our time limit will be overridden by any # time limits specified by the user through a # GAMS optfile, but tracking down the optfile # and/or the GAMS subsolver specific option # is more difficult - reslim_str = ( - "option reslim=" - f"{max(time_limit_buffer, time_remaining)};" - ) + reslim_str = "option reslim=" f"{max(time_limit_buffer, time_remaining)};" if isinstance(solver.options["add_options"], list): solver.options["add_options"].append(reslim_str) else: @@ -309,7 +306,8 @@ def adjust_solver_time_settings(timing_data_obj, solver, config): # IPOPT 3.14.0+ added support for specifying # wall time limit explicitly; this is preferred # over CPU time limit - "max_wall_time" if solver.version() >= (3, 14, 0, 0) + "max_wall_time" + if solver.version() >= (3, 14, 0, 0) else "max_cpu_time" ) elif isinstance(solver, SolverFactory.get_class("scip")): @@ -332,8 +330,7 @@ def adjust_solver_time_settings(timing_data_obj, solver, config): else original_max_time_setting ) solver.options[options_key] = min( - max(time_limit_buffer, time_remaining), - orig_max_time, + max(time_limit_buffer, time_remaining), orig_max_time ) else: custom_setting_present = False @@ -1814,10 +1811,7 @@ def call_solver(model, solver, config, timing_obj, timer_name, err_msg): try: results = solver.solve( - model, - tee=config.tee, - load_solutions=False, - symbolic_solver_labels=True, + model, tee=config.tee, load_solutions=False, symbolic_solver_labels=True ) except ApplicationError: # account for possible external subsolver errors @@ -1827,9 +1821,7 @@ def call_solver(model, solver, config, timing_obj, timer_name, err_msg): raise else: setattr( - results.solver, - TIC_TOC_SOLVE_TIME_ATTR, - tt_timer.toc(msg=None, delta=True), + results.solver, TIC_TOC_SOLVE_TIME_ATTR, tt_timer.toc(msg=None, delta=True) ) finally: timing_obj.stop_timer(timer_name) From dbe0529350c26de25f9acf71657e595ae22d90d9 Mon Sep 17 00:00:00 2001 From: jasherma Date: Mon, 18 Mar 2024 12:57:50 -0400 Subject: [PATCH 09/14] Update version number, changelog --- pyomo/contrib/pyros/CHANGELOG.txt | 11 +++++++++++ pyomo/contrib/pyros/pyros.py | 2 +- 2 files changed, 12 insertions(+), 1 deletion(-) diff --git a/pyomo/contrib/pyros/CHANGELOG.txt b/pyomo/contrib/pyros/CHANGELOG.txt index 94f4848edb2..52cd7a6db47 100644 --- a/pyomo/contrib/pyros/CHANGELOG.txt +++ b/pyomo/contrib/pyros/CHANGELOG.txt @@ -2,6 +2,17 @@ PyROS CHANGELOG =============== +------------------------------------------------------------------------------- +PyROS 1.2.11 17 Mar 2024 +------------------------------------------------------------------------------- +- Standardize calls to subordinate solvers across all PyROS subproblem types +- Account for user-specified subsolver time limits when automatically + adjusting subsolver time limits +- Add support for automatic adjustment of SCIP subsolver time limit +- Move start point of main PyROS solver timer to just before argument + validation begins + + ------------------------------------------------------------------------------- PyROS 1.2.10 07 Feb 2024 ------------------------------------------------------------------------------- diff --git a/pyomo/contrib/pyros/pyros.py b/pyomo/contrib/pyros/pyros.py index c74daf34c5f..c3335588b7b 100644 --- a/pyomo/contrib/pyros/pyros.py +++ b/pyomo/contrib/pyros/pyros.py @@ -44,7 +44,7 @@ from datetime import datetime -__version__ = "1.2.10" +__version__ = "1.2.11" default_pyros_solver_logger = setup_pyros_logger() From bd475d1a45ae34fff431694f74cb5f0d7b934535 Mon Sep 17 00:00:00 2001 From: jasherma Date: Thu, 28 Mar 2024 11:34:26 -0400 Subject: [PATCH 10/14] Fix docstring typo --- pyomo/contrib/pyros/util.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pyomo/contrib/pyros/util.py b/pyomo/contrib/pyros/util.py index 306141e9829..5d386240609 100644 --- a/pyomo/contrib/pyros/util.py +++ b/pyomo/contrib/pyros/util.py @@ -272,7 +272,7 @@ def adjust_solver_time_settings(timing_data_obj, solver, config): option. However, this may be overridden by any user specifications included in a GAMS optfile, which may be difficult to track down. - (3) To ensure the time limit is specified to a strictly + (4) To ensure the time limit is specified to a strictly positive value, the time limit is adjusted to a value of at least 1 second. """ From ef1464c5a3a02d032242ffe10df5ef3f7e753d22 Mon Sep 17 00:00:00 2001 From: jasherma Date: Thu, 28 Mar 2024 13:17:55 -0400 Subject: [PATCH 11/14] Restore PyROS intro and disclaimer logging --- pyomo/contrib/pyros/pyros.py | 20 ++++++++++++++++++-- 1 file changed, 18 insertions(+), 2 deletions(-) diff --git a/pyomo/contrib/pyros/pyros.py b/pyomo/contrib/pyros/pyros.py index c3335588b7b..582233c4a56 100644 --- a/pyomo/contrib/pyros/pyros.py +++ b/pyomo/contrib/pyros/pyros.py @@ -12,7 +12,6 @@ # pyros.py: Generalized Robust Cutting-Set Algorithm for Pyomo import logging from pyomo.common.config import document_kwargs_from_configdict -from pyomo.common.collections import Bunch from pyomo.core.base.block import Block from pyomo.core.expr import value from pyomo.core.base.var import Var @@ -20,7 +19,7 @@ from pyomo.contrib.pyros.util import time_code from pyomo.common.modeling import unique_component_name from pyomo.opt import SolverFactory -from pyomo.contrib.pyros.config import pyros_config +from pyomo.contrib.pyros.config import pyros_config, logger_domain from pyomo.contrib.pyros.util import ( recast_to_min_obj, add_decision_rule_constraints, @@ -347,6 +346,23 @@ def solve( global_solver=global_solver, ) ) + + # we want to log the intro and disclaimer in + # advance of assembling the config. + # this helps clarify to the user that any + # messages logged during assembly of the config + # were, in fact, logged after PyROS was initiated + progress_logger = logger_domain( + kwds.get( + "progress_logger", + kwds.get("options", dict()).get( + "progress_logger", default_pyros_solver_logger + ), + ) + ) + self._log_intro(logger=progress_logger, level=logging.INFO) + self._log_disclaimer(logger=progress_logger, level=logging.INFO) + config, state_vars = self._resolve_and_validate_pyros_args(model, **kwds) self._log_config( logger=config.progress_logger, From d9ca9879032a9da21a41f0ece5bf623e4553398f Mon Sep 17 00:00:00 2001 From: jasherma Date: Thu, 28 Mar 2024 13:32:37 -0400 Subject: [PATCH 12/14] Update PyROS solver logging docs example --- doc/OnlineDocs/contributed_packages/pyros.rst | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/doc/OnlineDocs/contributed_packages/pyros.rst b/doc/OnlineDocs/contributed_packages/pyros.rst index 76a751dd994..9faa6d1365f 100644 --- a/doc/OnlineDocs/contributed_packages/pyros.rst +++ b/doc/OnlineDocs/contributed_packages/pyros.rst @@ -903,10 +903,10 @@ Observe that the log contains the following information: :linenos: ============================================================================== - PyROS: The Pyomo Robust Optimization Solver, v1.2.9. - Pyomo version: 6.7.0 + PyROS: The Pyomo Robust Optimization Solver, v1.2.11. + Pyomo version: 6.7.2 Commit hash: unknown - Invoked at UTC 2023-12-16T00:00:00.000000 + Invoked at UTC 2024-03-28T00:00:00.000000 Developed by: Natalie M. Isenberg (1), Jason A. F. Sherman (1), John D. Siirola (2), Chrysanthos E. Gounaris (1) From 7b46ea5f2c6fecd38a260ccd56968493acb70911 Mon Sep 17 00:00:00 2001 From: jasherma Date: Fri, 5 Apr 2024 08:09:05 -0400 Subject: [PATCH 13/14] Make `symbolic_solver_labels` configurable --- pyomo/contrib/pyros/config.py | 15 +++++++++++++++ pyomo/contrib/pyros/tests/test_grcs.py | 2 ++ pyomo/contrib/pyros/util.py | 7 +++++-- 3 files changed, 22 insertions(+), 2 deletions(-) diff --git a/pyomo/contrib/pyros/config.py b/pyomo/contrib/pyros/config.py index bc2bfd591e6..8ab24939349 100644 --- a/pyomo/contrib/pyros/config.py +++ b/pyomo/contrib/pyros/config.py @@ -503,6 +503,21 @@ def pyros_config(): ), ), ) + CONFIG.declare( + 'symbolic_solver_labels', + ConfigValue( + default=False, + domain=bool, + description=( + """ + True to ensure the component names given to the + subordinate solvers for every subproblem reflect + the names of the corresponding Pyomo modeling components, + False otherwise. + """ + ), + ), + ) # ================================================ # === Required User Inputs diff --git a/pyomo/contrib/pyros/tests/test_grcs.py b/pyomo/contrib/pyros/tests/test_grcs.py index 41223b30899..d49ed6b1002 100644 --- a/pyomo/contrib/pyros/tests/test_grcs.py +++ b/pyomo/contrib/pyros/tests/test_grcs.py @@ -3795,6 +3795,7 @@ def test_solve_master(self): config.declare( "progress_logger", ConfigValue(default=logging.getLogger(__name__)) ) + config.declare("symbolic_solver_labels", ConfigValue(default=False)) with time_code(master_data.timing, "main", is_main_timer=True): master_soln = solve_master(master_data, config) @@ -6171,6 +6172,7 @@ def test_log_config(self): " keepfiles=False\n" " tee=False\n" " load_solution=True\n" + " symbolic_solver_labels=False\n" " objective_focus=\n" " nominal_uncertain_param_vals=[0.5]\n" " decision_rule_order=0\n" diff --git a/pyomo/contrib/pyros/util.py b/pyomo/contrib/pyros/util.py index 5d386240609..23cde45d0cf 100644 --- a/pyomo/contrib/pyros/util.py +++ b/pyomo/contrib/pyros/util.py @@ -1799,7 +1799,7 @@ def call_solver(model, solver, config, timing_obj, timer_name, err_msg): If ApplicationError is raised by the solver. In this case, `err_msg` is logged through ``config.progress_logger.exception()`` before - the excception is raised. + the exception is raised. """ tt_timer = TicTocTimer() @@ -1811,7 +1811,10 @@ def call_solver(model, solver, config, timing_obj, timer_name, err_msg): try: results = solver.solve( - model, tee=config.tee, load_solutions=False, symbolic_solver_labels=True + model, + tee=config.tee, + load_solutions=False, + symbolic_solver_labels=config.symbolic_solver_labels, ) except ApplicationError: # account for possible external subsolver errors From f766b33b2f7cea168a1a1b1ba49d49b8b7e4f546 Mon Sep 17 00:00:00 2001 From: jasherma Date: Fri, 5 Apr 2024 08:10:55 -0400 Subject: [PATCH 14/14] Make log example reflective of `symbolic_solver_labels` --- doc/OnlineDocs/contributed_packages/pyros.rst | 1 + 1 file changed, 1 insertion(+) diff --git a/doc/OnlineDocs/contributed_packages/pyros.rst b/doc/OnlineDocs/contributed_packages/pyros.rst index 9faa6d1365f..95049eded8a 100644 --- a/doc/OnlineDocs/contributed_packages/pyros.rst +++ b/doc/OnlineDocs/contributed_packages/pyros.rst @@ -926,6 +926,7 @@ Observe that the log contains the following information: keepfiles=False tee=False load_solution=True + symbolic_solver_labels=False objective_focus= nominal_uncertain_param_vals=[0.13248000000000001, 4.97, 4.97, 1800] decision_rule_order=1