From 4d00144c0e141eeda3bb9d4d06d55a6cd653a890 Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Tue, 30 Sep 2025 09:54:32 -0600 Subject: [PATCH 01/21] Fix two parsing bugs --- pyomo/contrib/solver/solvers/ipopt.py | 62 ++++++--- pyomo/contrib/solver/solvers/sol_reader.py | 26 +++- .../solver/tests/solvers/test_ipopt.py | 93 +++++++++++++ .../solver/tests/solvers/test_sol_reader.py | 127 ++++++++++++++++-- 4 files changed, 276 insertions(+), 32 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index a7ed5435aa7..d7358e341de 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -115,6 +115,12 @@ def get_reduced_costs( self, vars_to_load: Optional[Sequence[VarData]] = None ) -> Mapping[VarData, float]: self._error_check() + # If the NL instance has no objectives, report zeros + if not getattr(self._nl_info, "objectives", None): + vars_ = ( + vars_to_load if vars_to_load is not None else self._nl_info.variable_map + ) + return {v: 0.0 for v in vars_} if self._nl_info.scaling is None: scale_list = [1] * len(self._nl_info.variables) obj_scale = 1 @@ -610,41 +616,68 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] "ls", ] iterations = [] + n_expected_columns = len(columns) for line in iter_table: tokens = line.strip().split() - if len(tokens) != len(columns): + # Require at least the base columns + # Additionally allow optional trailing info-string(s) + if len(tokens) < n_expected_columns: continue - iter_data = dict(zip(columns, tokens)) + + expected_column_tokens = tokens[:n_expected_columns] + extra_tokens = tokens[n_expected_columns:] + + iter_data = dict(zip(columns, expected_column_tokens)) # Extract restoration flag from 'iter' - iter_data['restoration'] = iter_data['iter'].endswith('r') + iter_str = iter_data['iter'] + iter_data['restoration'] = iter_str.endswith('r') if iter_data['restoration']: - iter_data['iter'] = iter_data['iter'][:-1] - - # Separate alpha_pr into numeric part and optional tag - iter_data['step_acceptance'] = iter_data['alpha_pr'][-1] - if iter_data['step_acceptance'] in _ALPHA_PR_CHARS: + iter_str = iter_str[:-1] + # Keep numeric string for later + iter_data['iter'] = iter_str + + # Separate alpha_pr into numeric part and optional tag (f, D, R, etc.) + step_acceptance_tag = iter_data['alpha_pr'][-1] + if step_acceptance_tag in _ALPHA_PR_CHARS: + iter_data['step_acceptance'] = step_acceptance_tag iter_data['alpha_pr'] = iter_data['alpha_pr'][:-1] else: iter_data['step_acceptance'] = None + # Capture optional IPOPT info string if present + if extra_tokens: + # Typically a single string like 'q' or 'Nhj'; join just in case + iter_data['info_string'] = " ".join(extra_tokens) + # Attempt to cast all values to float where possible for key in columns: - if iter_data[key] == '-': + if key == 'iter': + continue + val = iter_data[key] + if val == '-': iter_data[key] = None else: try: - iter_data[key] = float(iter_data[key]) + iter_data[key] = float(val) except (ValueError, TypeError): logger.warning( "Error converting Ipopt log entry to " f"float:\n\t{sys.exc_info()[1]}\n\t{line}" ) - assert len(iterations) == iter_data.pop('iter'), ( - f"Parsed row in the iterations table\n\t{line}\ndoes not " - f"match the next expected iteration number ({len(iterations)})" + try: + iter_num = int(iter_data.pop('iter')) + except ValueError: + logger.warning( + "Could not parse IPOPT iteration number from line:\n\t%s", line + ) + continue + + assert len(iterations) == iter_num, ( + f"Parsed row in the iterations table\n\t{line}\n" + f"does not match the next expected iteration number ({len(iterations)})" ) iterations.append(iter_data) @@ -674,7 +707,6 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] "complementarity_error", "overall_nlp_error", ] - # Filter out None values and create final fields and values. # Nones occur in old-style IPOPT output (<= 3.13) zipped = [ @@ -684,10 +716,8 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] ) if scaled is not None and unscaled is not None ] - scaled = {k: float(s) for k, s, _ in zipped} unscaled = {k: float(u) for k, _, u in zipped} - parsed_data.update(unscaled) parsed_data['final_scaled_results'] = scaled diff --git a/pyomo/contrib/solver/solvers/sol_reader.py b/pyomo/contrib/solver/solvers/sol_reader.py index e580e2a72f9..fc9942ca8dc 100644 --- a/pyomo/contrib/solver/solvers/sol_reader.py +++ b/pyomo/contrib/solver/solvers/sol_reader.py @@ -117,6 +117,12 @@ def get_primals( def get_duals( self, cons_to_load: Optional[Sequence[ConstraintData]] = None ) -> Dict[ConstraintData, float]: + # If the NL instance has no objectives, report zeros + if not getattr(self._nl_info, "objectives", None): + cons = ( + cons_to_load if cons_to_load is not None else self._nl_info.constraints + ) + return {c: 0.0 for c in cons} if self._nl_info is None: raise RuntimeError( 'Solution loader does not currently have a valid solution. Please ' @@ -133,12 +139,22 @@ def get_duals( "have happened. Report this error to the Pyomo Developers." ) res = {} - if self._nl_info.scaling is None: - scale_list = [1] * len(self._nl_info.constraints) - obj_scale = 1 + # Set a default scaling + obj_scale = 1 + + scaling = getattr(self._nl_info, "scaling", None) + + # Objective scaling: first item if present + if scaling: + objectives = getattr(scaling, "objectives", None) + if objectives: + obj_scale = objectives[0] + + # Constraint scaling: list from scaling if present + if scaling and getattr(scaling, "constraints", None): + scale_list = scaling.constraints else: - scale_list = self._nl_info.scaling.constraints - obj_scale = self._nl_info.scaling.objectives[0] + scale_list = [1] * len(self._nl_info.constraints) if cons_to_load is None: cons_to_load = set(self._nl_info.constraints) else: diff --git a/pyomo/contrib/solver/tests/solvers/test_ipopt.py b/pyomo/contrib/solver/tests/solvers/test_ipopt.py index 06553da1bf0..70dc12d648e 100644 --- a/pyomo/contrib/solver/tests/solvers/test_ipopt.py +++ b/pyomo/contrib/solver/tests/solvers/test_ipopt.py @@ -321,6 +321,99 @@ def test_empty_output_parsing(self): logs.output[0], ) + def test_parse_output_info_string(self): + output = """****************************************************************************** +This program contains Ipopt, a library for large-scale nonlinear optimization. + Ipopt is released as open source code under the Eclipse Public License (EPL). + For more information visit http://projects.coin-or.org/Ipopt + +This version of Ipopt was compiled from source code available at + https://github.com/IDAES/Ipopt as part of the Institute for the Design of + Advanced Energy Systems Process Systems Engineering Framework (IDAES PSE + Framework) Copyright (c) 2018-2019. See https://github.com/IDAES/idaes-pse. + +This version of Ipopt was compiled using HSL, a collection of Fortran codes + for large-scale scientific computation. All technical papers, sales and + publicity material resulting from use of the HSL codes within IPOPT must + contain the following acknowledgement: + HSL, a collection of Fortran codes for large-scale scientific + computation. See http://www.hsl.rl.ac.uk/. +****************************************************************************** + +This is Ipopt version 3.13.2, running with linear solver ma57. + +Number of nonzeros in equality constraint Jacobian...: 77541 +Number of nonzeros in inequality constraint Jacobian.: 0 +Number of nonzeros in Lagrangian Hessian.............: 51855 + +Total number of variables............................: 15468 + variables with only lower bounds: 3491 + variables with lower and upper bounds: 5026 + variables with only upper bounds: 186 +Total number of equality constraints.................: 15417 +Total number of inequality constraints...............: 0 + inequality constraints with only lower bounds: 0 + inequality constraints with lower and upper bounds: 0 + inequality constraints with only upper bounds: 0 + +iter objective inf_pr inf_du lg(mu) ||d|| lg(rg) alpha_du alpha_pr ls + 0 4.3126674e+00 1.34e+00 1.00e+00 -5.0 0.00e+00 - 0.00e+00 0.00e+00 0 +Reallocating memory for MA57: lfact (2247250) + 1r 4.3126674e+00 1.34e+00 9.99e+02 0.1 0.00e+00 -4.0 0.00e+00 3.29e-10R 2 + 2r 3.0519246e+08 1.13e+00 9.90e+02 0.1 2.30e+02 - 2.60e-02 9.32e-03f 1 + 3r 2.2712595e+09 1.69e+00 9.73e+02 0.1 2.23e+02 - 2.54e-02 1.71e-02f 1 Nhj + 4 2.2712065e+09 1.69e+00 1.37e+09 -5.0 3.08e+03 - 1.32e-05 1.17e-05f 1 q + 5 1.9062986e+09 1.55e+00 1.25e+09 -5.0 5.13e+03 - 1.19e-01 8.38e-02f 1 + 6 1.7041594e+09 1.46e+00 1.18e+09 -5.0 5.66e+03 - 7.06e-02 5.45e-02f 1 + 7 1.4763158e+09 1.36e+00 1.10e+09 -5.0 3.94e+03 - 2.30e-01 6.92e-02f 1 + 8 8.5873108e+08 1.04e+00 8.41e+08 -5.0 2.38e+05 - 3.49e-06 2.37e-01f 1 + 9 4.4215572e+08 7.45e-01 6.03e+08 -5.0 1.63e+06 - 7.97e-02 2.82e-01f 1 +iter objective inf_pr inf_du lg(mu) ||d|| lg(rg) alpha_du alpha_pr ls + 10 5.0251884e+01 1.65e-01 1.57e+04 -5.0 1.24e+06 - 3.92e-05 1.00e+00f 1 + 11 4.9121733e+01 4.97e-02 4.68e+03 -5.0 8.11e+04 - 4.31e-02 7.01e-01h 1 + 12 4.1483985e+01 2.24e-02 5.97e+03 -5.0 1.15e+06 - 5.93e-02 1.00e+00f 1 + 13 3.5762585e+01 1.75e-02 5.00e+03 -5.0 1.03e+06 - 1.25e-01 1.00e+00f 1 + 14 3.2291014e+01 1.08e-02 3.51e+03 -5.0 8.25e+05 - 6.68e-01 1.00e+00f 1 + 15 3.2274630e+01 3.31e-05 1.17e+00 -5.0 4.26e+04 - 9.92e-01 1.00e+00h 1 + 16 3.2274631e+01 7.45e-09 2.71e-03 -5.0 6.11e+02 - 8.97e-01 1.00e+00h 1 + 17 3.2274635e+01 7.45e-09 2.35e-03 -5.0 2.71e+04 - 1.32e-01 1.00e+00f 1 + 18 3.2274635e+01 7.45e-09 1.15e-04 -5.0 5.53e+03 - 9.51e-01 1.00e+00h 1 + 19 3.2274635e+01 7.45e-09 2.84e-05 -5.0 4.41e+04 - 7.54e-01 1.00e+00f 1 +iter objective inf_pr inf_du lg(mu) ||d|| lg(rg) alpha_du alpha_pr ls + 20 3.2274635e+01 7.45e-09 8.54e-07 -5.0 1.83e+04 - 1.00e+00 1.00e+00h 1 + +Number of Iterations....: 20 + + (scaled) (unscaled) +Objective...............: 3.2274635418964841e+01 3.2274635418964841e+01 +Dual infeasibility......: 8.5365078678328669e-07 8.5365078678328669e-07 +Constraint violation....: 8.0780625068607930e-13 7.4505805969238281e-09 +Complementarity.........: 1.2275904566414160e-05 1.2275904566414160e-05 +Overall NLP error.......: 1.2275904566414160e-05 1.2275904566414160e-05 + + +Number of objective function evaluations = 23 +Number of objective gradient evaluations = 20 +Number of equality constraint evaluations = 23 +Number of inequality constraint evaluations = 0 +Number of equality constraint Jacobian evaluations = 22 +Number of inequality constraint Jacobian evaluations = 0 +Number of Lagrangian Hessian evaluations = 20 +Total CPU secs in IPOPT (w/o function evaluations) = 10.450 +Total CPU secs in NLP function evaluations = 1.651 + +EXIT: Optimal Solution Found. + """ + parsed_output = ipopt.Ipopt()._parse_ipopt_output(output) + self.assertEqual(parsed_output["iters"], 20) + self.assertEqual(len(parsed_output["iteration_log"]), 21) + self.assertEqual(parsed_output["incumbent_objective"], 3.2274635418964841e01) + self.assertEqual(parsed_output["iteration_log"][3]["info_string"], 'Nhj') + self.assertIn("final_scaled_results", parsed_output.keys()) + self.assertIn( + 'IPOPT (w/o function evaluations)', parsed_output['cpu_seconds'].keys() + ) + def test_verify_ipopt_options(self): opt = ipopt.Ipopt(solver_options={'max_iter': 4}) opt._verify_ipopt_options(opt.config) diff --git a/pyomo/contrib/solver/tests/solvers/test_sol_reader.py b/pyomo/contrib/solver/tests/solvers/test_sol_reader.py index 0db7934cd86..62d77341f65 100644 --- a/pyomo/contrib/solver/tests/solvers/test_sol_reader.py +++ b/pyomo/contrib/solver/tests/solvers/test_sol_reader.py @@ -9,10 +9,19 @@ # This software is distributed under the 3-clause BSD License. # ___________________________________________________________________________ +import io + +import pyomo.environ as pyo from pyomo.common import unittest +from pyomo.common.errors import PyomoException from pyomo.common.fileutils import this_file_dir from pyomo.common.tempfiles import TempfileManager -from pyomo.contrib.solver.solvers.sol_reader import SolFileData +from pyomo.contrib.solver.solvers.sol_reader import ( + SolSolutionLoader, + SolFileData, + parse_sol_file, +) +from pyomo.contrib.solver.common.results import Results currdir = this_file_dir() @@ -30,22 +39,118 @@ def test_default_instantiation(self): class TestSolParser(unittest.TestCase): - # I am not sure how to write these tests best since the sol parser requires - # not only a file but also the nl_info and results objects. def setUp(self): TempfileManager.push() def tearDown(self): TempfileManager.pop(remove=True) - def test_default_behavior(self): - pass + class _FakeNLInfo: + def __init__( + self, + variables, + constraints, + objectives=None, + scaling=None, + eliminated_vars=None, + ): + self.variables = variables + self.constraints = constraints + self.objectives = objectives or [] + self.scaling = scaling + self.eliminated_vars = eliminated_vars or [] + + class _FakeSolData: + def __init__(self, primals=None, duals=None): + self.primals = primals or [] + self.duals = duals or [] + self.var_suffixes = {} + self.con_suffixes = {} + self.obj_suffixes = {} + self.problem_suffixes = {} + self.other = [] + + def test_get_duals_no_objective_returns_zeros(self): + # model with 2 cons, no objective + m = pyo.ConcreteModel() + m.x = pyo.Var(initialize=1.0) + m.y = pyo.Var(initialize=2.0) + m.c1 = pyo.Constraint(expr=m.x + m.y >= 0) + m.c2 = pyo.Constraint(expr=m.x - m.y <= 3) + + nl_info = self._FakeNLInfo( + variables=[m.x, m.y], constraints=[m.c1, m.c2], objectives=[], scaling=None + ) + # solver returned some (non-zero) duals, but we should zero them out + sol_data = self._FakeSolData(duals=[123.0, -7.5]) + + loader = SolSolutionLoader(sol_data, nl_info) + duals = loader.get_duals() + self.assertEqual(duals[m.c1], 0.0) + self.assertEqual(duals[m.c2], 0.0) + + def test_parse_sol_file(self): + # Build a tiny .sol text stream: + # - "Options" block with number_of_options = 0, then 4 model_object ints + # model_objects[1] = #cons, model_objects[3] = #vars + # - #cons duals lines + # - #vars primals lines + # - "objno " + n_cons = 2 + n_vars = 3 + sol_content = ( + "Solver message preamble\n" + "Options\n" + "0\n" + f"0\n{n_cons}\n0\n{n_vars}\n" # model_objects (4 ints) + "1.5\n-2.25\n" # duals (2 lines) + "10.0\n20.0\n30.0\n" # primals (3 lines) + "objno 0 0\n" # exit code line + ) + stream = io.StringIO(sol_content) + + # Minimal NL info matching sizes + m = pyo.ConcreteModel() + m.v = pyo.Var(range(n_vars)) + m.c = pyo.Constraint(range(n_cons), rule=lambda m, i: m.v[0] >= -100) + nl_info = self._FakeNLInfo( + variables=[m.v[i] for i in range(n_vars)], + constraints=[m.c[i] for i in range(n_cons)], + ) + + res = Results() + res_out, sol_data = parse_sol_file(stream, nl_info, res) + + # Check counts populated + self.assertEqual(len(sol_data.duals), n_cons) + self.assertEqual(len(sol_data.primals), n_vars) + # Exit code 0..99 -> optimal + convergenceCriteriaSatisfied + self.assertEqual(res_out.solution_status.name, "optimal") + self.assertEqual( + res_out.termination_condition.name, "convergenceCriteriaSatisfied" + ) + + # Values preserved + self.assertAlmostEqual(sol_data.duals[0], 1.5) + self.assertAlmostEqual(sol_data.duals[1], -2.25) + self.assertEqual(sol_data.primals, [10.0, 20.0, 30.0]) + + def test_parse_sol_file_missing_options_raises(self): + # No line contains the substring "Options" + bad_text = "Solver message preamble\nNo header here\n" + stream = io.StringIO(bad_text) + + nl_info = self._FakeNLInfo(variables=[], constraints=[]) + + with self.assertRaises(PyomoException): + parse_sol_file(stream, nl_info, Results()) - def test_custom_behavior(self): - pass + def test_parse_sol_file_malformed_options_raises(self): + # Contains "Options" but the required integer line is missing/blank + bad_text = "Preamble\nOptions\n\n" + stream = io.StringIO(bad_text) - def test_infeasible1(self): - pass + nl_info = self._FakeNLInfo(variables=[], constraints=[]) - def test_infeasible2(self): - pass + with self.assertRaises(ValueError): + parse_sol_file(stream, nl_info, Results()) From 8032600dac10ffe59a5330fb254e537821d338f8 Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Tue, 30 Sep 2025 11:42:16 -0600 Subject: [PATCH 02/21] Remove usage of getattr --- pyomo/contrib/solver/solvers/ipopt.py | 6 +++--- pyomo/contrib/solver/solvers/sol_reader.py | 25 ++++++++++------------ 2 files changed, 14 insertions(+), 17 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index d7358e341de..03f8831ccb2 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -116,11 +116,11 @@ def get_reduced_costs( ) -> Mapping[VarData, float]: self._error_check() # If the NL instance has no objectives, report zeros - if not getattr(self._nl_info, "objectives", None): + if len(self._nl_info.objectives) == 0: vars_ = ( - vars_to_load if vars_to_load is not None else self._nl_info.variable_map + vars_to_load if vars_to_load is not None else self._nl_info.variables ) - return {v: 0.0 for v in vars_} + return ComponentMap((v, 0.0) for v in vars_) if self._nl_info.scaling is None: scale_list = [1] * len(self._nl_info.variables) obj_scale = 1 diff --git a/pyomo/contrib/solver/solvers/sol_reader.py b/pyomo/contrib/solver/solvers/sol_reader.py index fc9942ca8dc..bf365dad1e2 100644 --- a/pyomo/contrib/solver/solvers/sol_reader.py +++ b/pyomo/contrib/solver/solvers/sol_reader.py @@ -117,17 +117,17 @@ def get_primals( def get_duals( self, cons_to_load: Optional[Sequence[ConstraintData]] = None ) -> Dict[ConstraintData, float]: - # If the NL instance has no objectives, report zeros - if not getattr(self._nl_info, "objectives", None): - cons = ( - cons_to_load if cons_to_load is not None else self._nl_info.constraints - ) - return {c: 0.0 for c in cons} if self._nl_info is None: raise RuntimeError( 'Solution loader does not currently have a valid solution. Please ' 'check results.termination_condition and/or results.solution_status.' ) + # If the NL instance has no objectives, report zeros + if len(self._nl_info.objectives) == 0: + cons = ( + cons_to_load if cons_to_load is not None else self._nl_info.constraints + ) + return {c: 0.0 for c in cons} if len(self._nl_info.eliminated_vars) > 0: raise NotImplementedError( 'For now, turn presolve off (opt.config.writer_config.linear_presolve=False) ' @@ -141,20 +141,17 @@ def get_duals( res = {} # Set a default scaling obj_scale = 1 - - scaling = getattr(self._nl_info, "scaling", None) + scaling = self._nl_info.scaling # Objective scaling: first item if present - if scaling: - objectives = getattr(scaling, "objectives", None) - if objectives: - obj_scale = objectives[0] + if scaling and scaling.objectives: + obj_scale = scaling.objectives[0] # Constraint scaling: list from scaling if present - if scaling and getattr(scaling, "constraints", None): + if scaling and scaling.constraints: scale_list = scaling.constraints else: - scale_list = [1] * len(self._nl_info.constraints) + scale_list = [1.0] * len(self._nl_info.constraints) if cons_to_load is None: cons_to_load = set(self._nl_info.constraints) else: From edf05287493a5adee1865f916ae7621070b610dd Mon Sep 17 00:00:00 2001 From: Miranda Mundt <55767766+mrmundt@users.noreply.github.com> Date: Tue, 30 Sep 2025 12:41:56 -0600 Subject: [PATCH 03/21] Update pyomo/contrib/solver/solvers/ipopt.py Co-authored-by: John Siirola --- pyomo/contrib/solver/solvers/ipopt.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index 03f8831ccb2..c416145bdf4 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -625,11 +625,9 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] if len(tokens) < n_expected_columns: continue - expected_column_tokens = tokens[:n_expected_columns] + iter_data = dict(zip(columns, tokens)) extra_tokens = tokens[n_expected_columns:] - iter_data = dict(zip(columns, expected_column_tokens)) - # Extract restoration flag from 'iter' iter_str = iter_data['iter'] iter_data['restoration'] = iter_str.endswith('r') From 9e7c31b7f4af1cdd4507f088e2178f22dc687348 Mon Sep 17 00:00:00 2001 From: Miranda Mundt <55767766+mrmundt@users.noreply.github.com> Date: Tue, 30 Sep 2025 12:42:05 -0600 Subject: [PATCH 04/21] Update pyomo/contrib/solver/solvers/sol_reader.py Co-authored-by: John Siirola --- pyomo/contrib/solver/solvers/sol_reader.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pyomo/contrib/solver/solvers/sol_reader.py b/pyomo/contrib/solver/solvers/sol_reader.py index bf365dad1e2..e712d5179af 100644 --- a/pyomo/contrib/solver/solvers/sol_reader.py +++ b/pyomo/contrib/solver/solvers/sol_reader.py @@ -123,7 +123,7 @@ def get_duals( 'check results.termination_condition and/or results.solution_status.' ) # If the NL instance has no objectives, report zeros - if len(self._nl_info.objectives) == 0: + if not self._nl_info.objectives: cons = ( cons_to_load if cons_to_load is not None else self._nl_info.constraints ) From 0c7ffdaaf4fa8db0457f3ffb1a4816a2d3a2c2db Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Tue, 30 Sep 2025 14:30:42 -0600 Subject: [PATCH 05/21] Address jsiirola's comments --- pyomo/contrib/solver/solvers/ipopt.py | 88 ++++++++++++++----- pyomo/contrib/solver/solvers/sol_reader.py | 28 +++--- .../solver/tests/solvers/test_ipopt.py | 4 +- 3 files changed, 80 insertions(+), 40 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index c416145bdf4..e0bd9e23757 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -63,6 +63,43 @@ # Acceptable chars for the end of the alpha_pr column # in ipopt's output, per https://coin-or.github.io/Ipopt/OUTPUT.html _ALPHA_PR_CHARS = set("fFhHkKnNRwstTr") +_DIAGNOSTIC_TAGS = set( + { + "!", + "A", + "a", + "C", + "Dh", + "Dhj", + "Dj", + "dx", + "e", + "F-", + "F+", + "L", + "l", + "M", + "Nh", + "Nhj", + "Nj", + "NW", + "q", + "R", + "S", + "s", + "Tmax", + "W", + "w", + "Wb", + "We", + "Wp", + "Wr", + "Ws", + "WS", + "y", + "z", + } +) class IpoptConfig(SolverConfig): @@ -116,7 +153,7 @@ def get_reduced_costs( ) -> Mapping[VarData, float]: self._error_check() # If the NL instance has no objectives, report zeros - if len(self._nl_info.objectives) == 0: + if not len(self._nl_info.objectives): vars_ = ( vars_to_load if vars_to_load is not None else self._nl_info.variables ) @@ -620,21 +657,34 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] for line in iter_table: tokens = line.strip().split() - # Require at least the base columns - # Additionally allow optional trailing info-string(s) - if len(tokens) < n_expected_columns: - continue + # IPOPT sometimes mashes the first two column values together + # (e.g., "2r-4.93e-03"). We need to split them. + if tokens and (('-' in tokens[0][1:]) or ('+' in tokens[0][1:])): + m = re.match( + r'^(\d+r?)([+-](?:\d+(?:\.\d*)?|\.\d+)(?:[eE][+-]?\d+)?)$', + tokens[0], + ) + if m: + tokens = [m.group(1), m.group(2)] + tokens[1:] iter_data = dict(zip(columns, tokens)) extra_tokens = tokens[n_expected_columns:] # Extract restoration flag from 'iter' - iter_str = iter_data['iter'] - iter_data['restoration'] = iter_str.endswith('r') - if iter_data['restoration']: + iter_str = iter_data.pop("iter") + restoration = iter_str.endswith("r") + if restoration: iter_str = iter_str[:-1] - # Keep numeric string for later - iter_data['iter'] = iter_str + + try: + iter_num = int(iter_str) + except ValueError: + logger.error( + "Could not parse IPOPT iteration number from line:\n\t%s", line + ) + + iter_data["restoration"] = restoration + iter_data["iter"] = iter_num # Separate alpha_pr into numeric part and optional tag (f, D, R, etc.) step_acceptance_tag = iter_data['alpha_pr'][-1] @@ -644,10 +694,14 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] else: iter_data['step_acceptance'] = None - # Capture optional IPOPT info string if present + # Capture optional IPOPT diagnostic tags if present if extra_tokens: - # Typically a single string like 'q' or 'Nhj'; join just in case - iter_data['info_string'] = " ".join(extra_tokens) + if all(tok in _DIAGNOSTIC_TAGS for tok in extra_tokens): + iter_data['diagnostic_tags'] = "".join(extra_tokens) + else: + raise ValueError( + f"Unrecognized Ipopt diagnostic tags {extra_tokens} on line: {line}" + ) # Attempt to cast all values to float where possible for key in columns: @@ -665,14 +719,6 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] f"float:\n\t{sys.exc_info()[1]}\n\t{line}" ) - try: - iter_num = int(iter_data.pop('iter')) - except ValueError: - logger.warning( - "Could not parse IPOPT iteration number from line:\n\t%s", line - ) - continue - assert len(iterations) == iter_num, ( f"Parsed row in the iterations table\n\t{line}\n" f"does not match the next expected iteration number ({len(iterations)})" diff --git a/pyomo/contrib/solver/solvers/sol_reader.py b/pyomo/contrib/solver/solvers/sol_reader.py index e712d5179af..aff22ae39fc 100644 --- a/pyomo/contrib/solver/solvers/sol_reader.py +++ b/pyomo/contrib/solver/solvers/sol_reader.py @@ -142,25 +142,19 @@ def get_duals( # Set a default scaling obj_scale = 1 scaling = self._nl_info.scaling - - # Objective scaling: first item if present - if scaling and scaling.objectives: - obj_scale = scaling.objectives[0] - - # Constraint scaling: list from scaling if present - if scaling and scaling.constraints: - scale_list = scaling.constraints + if scaling: + _iter = zip( + self._nl_info.constraints, self._sol_data.duals, scaling.constraints + ) + obj_scale = self._nl_info.scaling.objectives[0] else: - scale_list = [1.0] * len(self._nl_info.constraints) - if cons_to_load is None: - cons_to_load = set(self._nl_info.constraints) + _iter = zip(self._nl_info.constraints, self._sol_data.duals) + if cons_to_load is not None: + _iter = filter(lambda x: x[0] in cons_to_load, _iter) + if scaling: + res = {con: val * scale / obj_scale for con, val, scale in _iter} else: - cons_to_load = set(cons_to_load) - for con, val, scale in zip( - self._nl_info.constraints, self._sol_data.duals, scale_list - ): - if con in cons_to_load: - res[con] = val * scale / obj_scale + res = {con: val for con, val in _iter} return res diff --git a/pyomo/contrib/solver/tests/solvers/test_ipopt.py b/pyomo/contrib/solver/tests/solvers/test_ipopt.py index 70dc12d648e..4d5bde103a6 100644 --- a/pyomo/contrib/solver/tests/solvers/test_ipopt.py +++ b/pyomo/contrib/solver/tests/solvers/test_ipopt.py @@ -321,7 +321,7 @@ def test_empty_output_parsing(self): logs.output[0], ) - def test_parse_output_info_string(self): + def test_parse_output_diagnostic_tags(self): output = """****************************************************************************** This program contains Ipopt, a library for large-scale nonlinear optimization. Ipopt is released as open source code under the Eclipse Public License (EPL). @@ -408,7 +408,7 @@ def test_parse_output_info_string(self): self.assertEqual(parsed_output["iters"], 20) self.assertEqual(len(parsed_output["iteration_log"]), 21) self.assertEqual(parsed_output["incumbent_objective"], 3.2274635418964841e01) - self.assertEqual(parsed_output["iteration_log"][3]["info_string"], 'Nhj') + self.assertEqual(parsed_output["iteration_log"][3]["diagnostic_tags"], 'Nhj') self.assertIn("final_scaled_results", parsed_output.keys()) self.assertIn( 'IPOPT (w/o function evaluations)', parsed_output['cpu_seconds'].keys() From b9b14533bda7812559bc1f0afa9e08d4202b8e75 Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Tue, 30 Sep 2025 15:58:01 -0600 Subject: [PATCH 06/21] Return empty ComponentMap --- pyomo/contrib/solver/solvers/ipopt.py | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index e0bd9e23757..a65a2835608 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -154,10 +154,7 @@ def get_reduced_costs( self._error_check() # If the NL instance has no objectives, report zeros if not len(self._nl_info.objectives): - vars_ = ( - vars_to_load if vars_to_load is not None else self._nl_info.variables - ) - return ComponentMap((v, 0.0) for v in vars_) + return ComponentMap() if self._nl_info.scaling is None: scale_list = [1] * len(self._nl_info.variables) obj_scale = 1 From cbc3293e12840e6b43cc446a57f7fb33685e9b82 Mon Sep 17 00:00:00 2001 From: Miranda Mundt <55767766+mrmundt@users.noreply.github.com> Date: Wed, 1 Oct 2025 19:39:42 -0600 Subject: [PATCH 07/21] S is in _ALPHA_PR_CHARS --- pyomo/contrib/solver/solvers/ipopt.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index a65a2835608..d934febc57d 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -62,7 +62,7 @@ # Acceptable chars for the end of the alpha_pr column # in ipopt's output, per https://coin-or.github.io/Ipopt/OUTPUT.html -_ALPHA_PR_CHARS = set("fFhHkKnNRwstTr") +_ALPHA_PR_CHARS = set("fFhHkKnNRwSstTr") _DIAGNOSTIC_TAGS = set( { "!", From b4fea1ed85b4c0c00f9958953e6313b28c4f044a Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Fri, 3 Oct 2025 10:31:33 -0600 Subject: [PATCH 08/21] Add in tests for print levels (catching a new bug in the process) --- pyomo/contrib/solver/solvers/ipopt.py | 17 ++++++---- .../solver/tests/solvers/test_ipopt.py | 33 +++++++++++++++++++ 2 files changed, 43 insertions(+), 7 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index d934febc57d..bed0ffe0b00 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -505,6 +505,7 @@ def solve(self, model, **kwds) -> Results: # This is the data we need to parse to get the iterations # and time parsed_output_data = self._parse_ipopt_output(ostreams[0]) + parsed_output_message = f"Parsed solver data: {parsed_output_data}" if proven_infeasible: results = Results() @@ -545,17 +546,19 @@ def solve(self, model, **kwds) -> Results: for k, v in cpu_seconds.items(): results.timing_info[k] = v results.extra_info = parsed_output_data - # Set iteration_log visibility to ADVANCED_OPTION because it's - # a lot to print out with `display` - results.extra_info.get("iteration_log")._visibility = ( - ADVANCED_OPTION - ) - except KeyError as e: + iter_log = results.extra_info.get("iteration_log", None) + if iter_log is not None: + # Only set if object supports the attribute + try: + iter_log._visibility = ADVANCED_OPTION + except Exception: + pass + except Exception as e: logger.log( logging.WARNING, "The solver output data is empty or incomplete.\n" f"Full error message: {e}\n" - f"Parsed solver data: {parsed_output_data}\n", + f"{parsed_output_message}\n", ) if ( config.raise_exception_on_nonoptimal_result diff --git a/pyomo/contrib/solver/tests/solvers/test_ipopt.py b/pyomo/contrib/solver/tests/solvers/test_ipopt.py index 4d5bde103a6..fd43d159829 100644 --- a/pyomo/contrib/solver/tests/solvers/test_ipopt.py +++ b/pyomo/contrib/solver/tests/solvers/test_ipopt.py @@ -571,6 +571,39 @@ def test_ipopt_solve(self): self.assertAlmostEqual(model.x.value, 1) self.assertAlmostEqual(model.y.value, 1) + def test_ipopt_quiet_print_level(self): + model = self.create_model() + result = ipopt.Ipopt().solve(model, solver_options={'print_level': 0}) + # IPOPT doesn't tell us anything about the iters if the print level + # is set to 0 + self.assertIsNone(result.iteration_count) + self.assertFalse(hasattr(result.extra_info, 'iteration_log')) + model = self.create_model() + result = ipopt.Ipopt().solve(model, tee=True, solver_options={'print_level': 3}) + # At a slightly higher level, we get some of the info, like + # iteration count, but NOT iteration_log + self.assertEqual(result.iteration_count, 11) + self.assertFalse(hasattr(result.extra_info, 'iteration_log')) + result.display(visibility=ADVANCED_OPTION) + + def test_ipopt_loud_print_level(self): + model = self.create_model() + result = ipopt.Ipopt().solve(model, solver_options={'print_level': 8}) + # Nothing unexpected should be in the results object at this point, + # except that the solver_log is significantly longer + self.assertEqual(result.iteration_count, 11) + self.assertEqual(result.incumbent_objective, 7.013645951336496e-25) + self.assertIn('Optimal Solution Found', result.extra_info.solver_message) + self.assertTrue(hasattr(result.extra_info, 'iteration_log')) + model = self.create_model() + result = ipopt.Ipopt().solve( + model, tee=True, solver_options={'print_level': 12} + ) + self.assertEqual(result.iteration_count, 11) + self.assertEqual(result.incumbent_objective, 7.013645951336496e-25) + self.assertIn('Optimal Solution Found', result.extra_info.solver_message) + self.assertTrue(hasattr(result.extra_info, 'iteration_log')) + def test_ipopt_results(self): model = self.create_model() results = ipopt.Ipopt().solve(model) From 89e021f531b9654191a961e6e2fbf461a7180451 Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Fri, 3 Oct 2025 10:35:40 -0600 Subject: [PATCH 09/21] Residual debugging print stuff --- pyomo/contrib/solver/tests/solvers/test_ipopt.py | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-) diff --git a/pyomo/contrib/solver/tests/solvers/test_ipopt.py b/pyomo/contrib/solver/tests/solvers/test_ipopt.py index fd43d159829..2f408c60da8 100644 --- a/pyomo/contrib/solver/tests/solvers/test_ipopt.py +++ b/pyomo/contrib/solver/tests/solvers/test_ipopt.py @@ -579,12 +579,11 @@ def test_ipopt_quiet_print_level(self): self.assertIsNone(result.iteration_count) self.assertFalse(hasattr(result.extra_info, 'iteration_log')) model = self.create_model() - result = ipopt.Ipopt().solve(model, tee=True, solver_options={'print_level': 3}) + result = ipopt.Ipopt().solve(model, solver_options={'print_level': 3}) # At a slightly higher level, we get some of the info, like # iteration count, but NOT iteration_log self.assertEqual(result.iteration_count, 11) self.assertFalse(hasattr(result.extra_info, 'iteration_log')) - result.display(visibility=ADVANCED_OPTION) def test_ipopt_loud_print_level(self): model = self.create_model() @@ -596,9 +595,7 @@ def test_ipopt_loud_print_level(self): self.assertIn('Optimal Solution Found', result.extra_info.solver_message) self.assertTrue(hasattr(result.extra_info, 'iteration_log')) model = self.create_model() - result = ipopt.Ipopt().solve( - model, tee=True, solver_options={'print_level': 12} - ) + result = ipopt.Ipopt().solve(model, solver_options={'print_level': 12}) self.assertEqual(result.iteration_count, 11) self.assertEqual(result.incumbent_objective, 7.013645951336496e-25) self.assertIn('Optimal Solution Found', result.extra_info.solver_message) @@ -738,7 +735,6 @@ def test_map_OF_options(self): solver_options={'OF_bogus_option': 5}, load_solutions=False, ) - print(LOG.getvalue()) self.assertIn('OPTION_INVALID', LOG.getvalue()) # Note: OF_ is stripped self.assertIn( From 393f61bab911e39bdc901f75100dcbe815e0a7f3 Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Mon, 6 Oct 2025 13:22:59 -0600 Subject: [PATCH 10/21] Apply requested changes --- pyomo/contrib/solver/solvers/ipopt.py | 48 +++++++++---------- pyomo/contrib/solver/solvers/sol_reader.py | 2 - .../solver/tests/solvers/test_ipopt.py | 2 +- 3 files changed, 24 insertions(+), 28 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index bed0ffe0b00..2a53bc7d9fb 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -334,7 +334,7 @@ def has_linear_solver(self, linear_solver: str) -> bool: def _verify_ipopt_options(self, config: IpoptConfig) -> None: for key, msg in unallowed_ipopt_options.items(): if key in config.solver_options: - raise ValueError(f"unallowed ipopt option '{key}': {msg}") + raise ValueError(f"unallowed Ipopt option '{key}': {msg}") # Map standard Pyomo solver options to Ipopt options: standard # options override ipopt-specific options. if config.time_limit is not None: @@ -548,11 +548,7 @@ def solve(self, model, **kwds) -> Results: results.extra_info = parsed_output_data iter_log = results.extra_info.get("iteration_log", None) if iter_log is not None: - # Only set if object supports the attribute - try: - iter_log._visibility = ADVANCED_OPTION - except Exception: - pass + iter_log._visibility = ADVANCED_OPTION except Exception as e: logger.log( logging.WARNING, @@ -659,28 +655,26 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] tokens = line.strip().split() # IPOPT sometimes mashes the first two column values together # (e.g., "2r-4.93e-03"). We need to split them. - if tokens and (('-' in tokens[0][1:]) or ('+' in tokens[0][1:])): - m = re.match( - r'^(\d+r?)([+-](?:\d+(?:\.\d*)?|\.\d+)(?:[eE][+-]?\d+)?)$', - tokens[0], - ) - if m: - tokens = [m.group(1), m.group(2)] + tokens[1:] + try: + idx = tokens[0].index('-') + tokens[:1] = (tokens[0][:idx], tokens[0][idx:]) + except ValueError: + # No '-' found, leave as-is + pass iter_data = dict(zip(columns, tokens)) extra_tokens = tokens[n_expected_columns:] # Extract restoration flag from 'iter' - iter_str = iter_data.pop("iter") - restoration = iter_str.endswith("r") + iter_num = iter_data.pop("iter") + restoration = iter_num.endswith("r") if restoration: - iter_str = iter_str[:-1] - + iter_num = iter_num[:-1] try: - iter_num = int(iter_str) + iter_num = int(iter_num) except ValueError: - logger.error( - "Could not parse IPOPT iteration number from line:\n\t%s", line + raise ValueError( + f"Could not parse Ipopt iteration number: {iter_num}" ) iter_data["restoration"] = restoration @@ -704,10 +698,14 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] ) # Attempt to cast all values to float where possible - for key in columns: - if key == 'iter': + for key, val in iter_data.items(): + if key in { + 'iter', + 'restoration', + 'step_acceptance', + 'diagnostic_tags', + }: continue - val = iter_data[key] if val == '-': iter_data[key] = None else: @@ -720,8 +718,8 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] ) assert len(iterations) == iter_num, ( - f"Parsed row in the iterations table\n\t{line}\n" - f"does not match the next expected iteration number ({len(iterations)})" + f"Total number of iterations logged ({iterations}) does " + f"not match the parsed number of iterations ({iter_num})." ) iterations.append(iter_data) diff --git a/pyomo/contrib/solver/solvers/sol_reader.py b/pyomo/contrib/solver/solvers/sol_reader.py index aff22ae39fc..7d2f613eb6a 100644 --- a/pyomo/contrib/solver/solvers/sol_reader.py +++ b/pyomo/contrib/solver/solvers/sol_reader.py @@ -139,8 +139,6 @@ def get_duals( "have happened. Report this error to the Pyomo Developers." ) res = {} - # Set a default scaling - obj_scale = 1 scaling = self._nl_info.scaling if scaling: _iter = zip( diff --git a/pyomo/contrib/solver/tests/solvers/test_ipopt.py b/pyomo/contrib/solver/tests/solvers/test_ipopt.py index 2f408c60da8..b8e0699e85a 100644 --- a/pyomo/contrib/solver/tests/solvers/test_ipopt.py +++ b/pyomo/contrib/solver/tests/solvers/test_ipopt.py @@ -741,7 +741,7 @@ def test_map_OF_options(self): 'Read Option: "bogus_option". It is not a valid option', LOG.getvalue() ) - with self.assertRaisesRegex(ValueError, "unallowed ipopt option 'wantsol'"): + with self.assertRaisesRegex(ValueError, "unallowed Ipopt option 'wantsol'"): results = ipopt.LegacyIpoptSolver().solve( model, tee=True, From b5d8608f8ce92bb392244e1021a70213d02426bc Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Mon, 6 Oct 2025 14:23:00 -0600 Subject: [PATCH 11/21] Add regex back in, fix incorrect assertion language --- pyomo/contrib/solver/solvers/ipopt.py | 17 +++++++++-------- 1 file changed, 9 insertions(+), 8 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index 2a53bc7d9fb..c16cc8687f4 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -655,12 +655,12 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] tokens = line.strip().split() # IPOPT sometimes mashes the first two column values together # (e.g., "2r-4.93e-03"). We need to split them. - try: - idx = tokens[0].index('-') - tokens[:1] = (tokens[0][:idx], tokens[0][idx:]) - except ValueError: - # No '-' found, leave as-is - pass + m = re.match( + r'^(\d+r?)([+-](?:\d+(?:\.\d*)?|\.\d+)(?:[eE][+-]?\d+)?)$', + tokens[0], + ) + if m: + tokens = [m.group(1), m.group(2)] + tokens[1:] iter_data = dict(zip(columns, tokens)) extra_tokens = tokens[n_expected_columns:] @@ -718,8 +718,9 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] ) assert len(iterations) == iter_num, ( - f"Total number of iterations logged ({iterations}) does " - f"not match the parsed number of iterations ({iter_num})." + f"Total number of iterations logged ({len(iterations)}) does " + f"not match the parsed number of iterations ({iter_num}). " + f"Processed iterations: {iterations}" ) iterations.append(iter_data) From 24ddea757db05a09b5064e429c4d4a52b45056bf Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Mon, 6 Oct 2025 15:21:03 -0600 Subject: [PATCH 12/21] Not sure what's goiing on with windows --- pyomo/contrib/solver/solvers/ipopt.py | 15 ++++++--------- 1 file changed, 6 insertions(+), 9 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index c16cc8687f4..1c5714a0a5c 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -648,6 +648,8 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] "alpha_pr", "ls", ] + numerical_columns = set(columns) + numerical_columns.remove('iter') iterations = [] n_expected_columns = len(columns) @@ -670,6 +672,7 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] restoration = iter_num.endswith("r") if restoration: iter_num = iter_num[:-1] + try: iter_num = int(iter_num) except ValueError: @@ -699,12 +702,7 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] # Attempt to cast all values to float where possible for key, val in iter_data.items(): - if key in { - 'iter', - 'restoration', - 'step_acceptance', - 'diagnostic_tags', - }: + if key not in numerical_columns: continue if val == '-': iter_data[key] = None @@ -718,9 +716,8 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] ) assert len(iterations) == iter_num, ( - f"Total number of iterations logged ({len(iterations)}) does " - f"not match the parsed number of iterations ({iter_num}). " - f"Processed iterations: {iterations}" + f"Total number of iterations parsed {len(iterations)}\n" + f"does not match the expected iteration number ({iter_num})." ) iterations.append(iter_data) From 31b614363e367a68b82e558b14d3b5318f60a134 Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Mon, 6 Oct 2025 16:08:26 -0600 Subject: [PATCH 13/21] Try one more time --- pyomo/contrib/solver/solvers/ipopt.py | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index 1c5714a0a5c..afaf8319161 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -657,12 +657,13 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] tokens = line.strip().split() # IPOPT sometimes mashes the first two column values together # (e.g., "2r-4.93e-03"). We need to split them. - m = re.match( - r'^(\d+r?)([+-](?:\d+(?:\.\d*)?|\.\d+)(?:[eE][+-]?\d+)?)$', - tokens[0], - ) - if m: - tokens = [m.group(1), m.group(2)] + tokens[1:] + try: + idx = tokens[0].index('-') + head = tokens[0][:idx] + if head and head.rstrip('r').isdigit(): + tokens[:1] = (head, tokens[0][idx:]) + except ValueError: + pass iter_data = dict(zip(columns, tokens)) extra_tokens = tokens[n_expected_columns:] From 2ab4ee826ff876adf8c1bb00ed3d5825b55b08f7 Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Tue, 7 Oct 2025 09:46:13 -0600 Subject: [PATCH 14/21] Print the output so I can figure out what's going on --- pyomo/contrib/solver/solvers/ipopt.py | 3 +++ 1 file changed, 3 insertions(+) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index afaf8319161..1c0cacae4d0 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -621,6 +621,9 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] if isinstance(output, io.StringIO): output = output.getvalue() + print("************* Raw output:\n") + print(output) + # Stop parsing if there is nothing to parse if not output: logger.log( From 385b872820f7445ca271d7e21f1c30794bc5685a Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Tue, 7 Oct 2025 10:44:35 -0600 Subject: [PATCH 15/21] Different print data because now the error has changed --- pyomo/contrib/solver/solvers/ipopt.py | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index 1c0cacae4d0..22468743a00 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -621,9 +621,6 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] if isinstance(output, io.StringIO): output = output.getvalue() - print("************* Raw output:\n") - print(output) - # Stop parsing if there is nothing to parse if not output: logger.log( @@ -639,6 +636,7 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] # Gather all the iteration data iter_table = re.findall(r'^(?:\s*\d+.*?)$', output, re.MULTILINE) if iter_table: + print("********* Full iteration table:\n", iter_table) columns = [ "iter", "objective", @@ -657,6 +655,7 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] n_expected_columns = len(columns) for line in iter_table: + print("********* Current line:\n", line) tokens = line.strip().split() # IPOPT sometimes mashes the first two column values together # (e.g., "2r-4.93e-03"). We need to split them. From 06674ed192a1df258e9bc36913626942f9ee15f7 Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Tue, 7 Oct 2025 11:25:52 -0600 Subject: [PATCH 16/21] Turn off NOWAIT --- pyomo/common/tee.py | 2 +- pyomo/contrib/solver/solvers/ipopt.py | 3 +++ 2 files changed, 4 insertions(+), 1 deletion(-) diff --git a/pyomo/common/tee.py b/pyomo/common/tee.py index 0711d831bf4..d0c63ec1e3d 100644 --- a/pyomo/common/tee.py +++ b/pyomo/common/tee.py @@ -47,7 +47,7 @@ from win32pipe import FdCreatePipe, PeekNamedPipe, SetNamedPipeHandleState # This constant from Microsoft SetNamedPipeHandleState documentation: - PIPE_NOWAIT = 1 + PIPE_NOWAIT = 0 else: from select import select _peek_available = True diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index 22468743a00..3357ea400c3 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -621,6 +621,9 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] if isinstance(output, io.StringIO): output = output.getvalue() + print("************* Raw output:\n") + print(output) + # Stop parsing if there is nothing to parse if not output: logger.log( From e615ddd1c2df5dcb9380df015b967548398cb841 Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Tue, 7 Oct 2025 12:30:49 -0600 Subject: [PATCH 17/21] Remove erroneous print statements --- pyomo/contrib/solver/solvers/ipopt.py | 5 ----- 1 file changed, 5 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index 3357ea400c3..afaf8319161 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -621,9 +621,6 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] if isinstance(output, io.StringIO): output = output.getvalue() - print("************* Raw output:\n") - print(output) - # Stop parsing if there is nothing to parse if not output: logger.log( @@ -639,7 +636,6 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] # Gather all the iteration data iter_table = re.findall(r'^(?:\s*\d+.*?)$', output, re.MULTILINE) if iter_table: - print("********* Full iteration table:\n", iter_table) columns = [ "iter", "objective", @@ -658,7 +654,6 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] n_expected_columns = len(columns) for line in iter_table: - print("********* Current line:\n", line) tokens = line.strip().split() # IPOPT sometimes mashes the first two column values together # (e.g., "2r-4.93e-03"). We need to split them. From 94c2bcd4f6047e85d520d95d82e06980114142cb Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Tue, 7 Oct 2025 12:58:08 -0600 Subject: [PATCH 18/21] Log warnings instead of raising errors --- pyomo/contrib/solver/solvers/ipopt.py | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index afaf8319161..71e2d32862b 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -677,7 +677,7 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] try: iter_num = int(iter_num) except ValueError: - raise ValueError( + logger.warning( f"Could not parse Ipopt iteration number: {iter_num}" ) @@ -697,7 +697,7 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] if all(tok in _DIAGNOSTIC_TAGS for tok in extra_tokens): iter_data['diagnostic_tags'] = "".join(extra_tokens) else: - raise ValueError( + logger.warning( f"Unrecognized Ipopt diagnostic tags {extra_tokens} on line: {line}" ) @@ -716,10 +716,11 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] f"float:\n\t{sys.exc_info()[1]}\n\t{line}" ) - assert len(iterations) == iter_num, ( - f"Total number of iterations parsed {len(iterations)}\n" - f"does not match the expected iteration number ({iter_num})." - ) + if len(iterations) != iter_num: + logger.warning( + f"Total number of iterations parsed {len(iterations)} " + f"does not match the expected iteration number ({iter_num})." + ) iterations.append(iter_data) parsed_data['iteration_log'] = iterations From 4a52dfc4638efae66c55ffe087272ea28a5e5ffe Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Tue, 7 Oct 2025 13:58:11 -0600 Subject: [PATCH 19/21] Make the buffer msmall --- pyomo/common/tee.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pyomo/common/tee.py b/pyomo/common/tee.py index d0c63ec1e3d..ea1c6fa20bb 100644 --- a/pyomo/common/tee.py +++ b/pyomo/common/tee.py @@ -37,7 +37,7 @@ # ~(13.1 * #threads) seconds _poll_timeout = 1 # 14 rounds: 0.0001 * 2**14 == 1.6384 _poll_timeout_deadlock = 100 # seconds -_pipe_buffersize = 1 << 16 # 65536 +_pipe_buffersize = 1 << 10 # 1024 _noop = lambda: None _mswindows = sys.platform.startswith('win') try: From 56e8df6fa75335cc410c017e75eb617aeea888ad Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Tue, 7 Oct 2025 15:00:12 -0600 Subject: [PATCH 20/21] Introduce a labuffer increase context manager for the ipopt tests --- pyomo/common/tee.py | 4 +- .../solver/tests/solvers/test_ipopt.py | 49 +++++++++++++------ 2 files changed, 36 insertions(+), 17 deletions(-) diff --git a/pyomo/common/tee.py b/pyomo/common/tee.py index ea1c6fa20bb..0711d831bf4 100644 --- a/pyomo/common/tee.py +++ b/pyomo/common/tee.py @@ -37,7 +37,7 @@ # ~(13.1 * #threads) seconds _poll_timeout = 1 # 14 rounds: 0.0001 * 2**14 == 1.6384 _poll_timeout_deadlock = 100 # seconds -_pipe_buffersize = 1 << 10 # 1024 +_pipe_buffersize = 1 << 16 # 65536 _noop = lambda: None _mswindows = sys.platform.startswith('win') try: @@ -47,7 +47,7 @@ from win32pipe import FdCreatePipe, PeekNamedPipe, SetNamedPipeHandleState # This constant from Microsoft SetNamedPipeHandleState documentation: - PIPE_NOWAIT = 0 + PIPE_NOWAIT = 1 else: from select import select _peek_available = True diff --git a/pyomo/contrib/solver/tests/solvers/test_ipopt.py b/pyomo/contrib/solver/tests/solvers/test_ipopt.py index b8e0699e85a..f88b18300f4 100644 --- a/pyomo/contrib/solver/tests/solvers/test_ipopt.py +++ b/pyomo/contrib/solver/tests/solvers/test_ipopt.py @@ -9,8 +9,9 @@ # This software is distributed under the 3-clause BSD License. # ___________________________________________________________________________ -import os +import os, sys import subprocess +from contextlib import contextmanager import pyomo.environ as pyo from pyomo.common.envvar import is_windows @@ -29,6 +30,23 @@ ipopt_available = ipopt.Ipopt().available() +@contextmanager +def windows_tee_buffer(size=1 << 20): + """Temporarily increase TeeStream buffer size on Windows""" + if not sys.platform.startswith("win"): + # Only windows has an issue + yield + return + import pyomo.common.tee as tee + + old = tee._pipe_buffersize + tee._pipe_buffersize = size + try: + yield + finally: + tee._pipe_buffersize = old + + @unittest.skipIf(not ipopt_available, "The 'ipopt' command is not available") class TestIpoptSolverConfig(unittest.TestCase): def test_default_instantiation(self): @@ -586,20 +604,21 @@ def test_ipopt_quiet_print_level(self): self.assertFalse(hasattr(result.extra_info, 'iteration_log')) def test_ipopt_loud_print_level(self): - model = self.create_model() - result = ipopt.Ipopt().solve(model, solver_options={'print_level': 8}) - # Nothing unexpected should be in the results object at this point, - # except that the solver_log is significantly longer - self.assertEqual(result.iteration_count, 11) - self.assertEqual(result.incumbent_objective, 7.013645951336496e-25) - self.assertIn('Optimal Solution Found', result.extra_info.solver_message) - self.assertTrue(hasattr(result.extra_info, 'iteration_log')) - model = self.create_model() - result = ipopt.Ipopt().solve(model, solver_options={'print_level': 12}) - self.assertEqual(result.iteration_count, 11) - self.assertEqual(result.incumbent_objective, 7.013645951336496e-25) - self.assertIn('Optimal Solution Found', result.extra_info.solver_message) - self.assertTrue(hasattr(result.extra_info, 'iteration_log')) + with windows_tee_buffer(1 << 20): + model = self.create_model() + result = ipopt.Ipopt().solve(model, solver_options={'print_level': 8}) + # Nothing unexpected should be in the results object at this point, + # except that the solver_log is significantly longer + self.assertEqual(result.iteration_count, 11) + self.assertEqual(result.incumbent_objective, 7.013645951336496e-25) + self.assertIn('Optimal Solution Found', result.extra_info.solver_message) + self.assertTrue(hasattr(result.extra_info, 'iteration_log')) + model = self.create_model() + result = ipopt.Ipopt().solve(model, solver_options={'print_level': 12}) + self.assertEqual(result.iteration_count, 11) + self.assertEqual(result.incumbent_objective, 7.013645951336496e-25) + self.assertIn('Optimal Solution Found', result.extra_info.solver_message) + self.assertTrue(hasattr(result.extra_info, 'iteration_log')) def test_ipopt_results(self): model = self.create_model() From d9b15db00e281bd796c31be1e5545ee7a39dc2f7 Mon Sep 17 00:00:00 2001 From: Miranda Mundt Date: Mon, 13 Oct 2025 13:37:09 -0600 Subject: [PATCH 21/21] Address jsiirola comments --- pyomo/contrib/solver/solvers/ipopt.py | 54 ++------------------------- 1 file changed, 4 insertions(+), 50 deletions(-) diff --git a/pyomo/contrib/solver/solvers/ipopt.py b/pyomo/contrib/solver/solvers/ipopt.py index 71e2d32862b..7c73e07af38 100644 --- a/pyomo/contrib/solver/solvers/ipopt.py +++ b/pyomo/contrib/solver/solvers/ipopt.py @@ -63,43 +63,6 @@ # Acceptable chars for the end of the alpha_pr column # in ipopt's output, per https://coin-or.github.io/Ipopt/OUTPUT.html _ALPHA_PR_CHARS = set("fFhHkKnNRwSstTr") -_DIAGNOSTIC_TAGS = set( - { - "!", - "A", - "a", - "C", - "Dh", - "Dhj", - "Dj", - "dx", - "e", - "F-", - "F+", - "L", - "l", - "M", - "Nh", - "Nhj", - "Nj", - "NW", - "q", - "R", - "S", - "s", - "Tmax", - "W", - "w", - "Wb", - "We", - "Wp", - "Wr", - "Ws", - "WS", - "y", - "z", - } -) class IpoptConfig(SolverConfig): @@ -505,7 +468,6 @@ def solve(self, model, **kwds) -> Results: # This is the data we need to parse to get the iterations # and time parsed_output_data = self._parse_ipopt_output(ostreams[0]) - parsed_output_message = f"Parsed solver data: {parsed_output_data}" if proven_infeasible: results = Results() @@ -554,7 +516,7 @@ def solve(self, model, **kwds) -> Results: logging.WARNING, "The solver output data is empty or incomplete.\n" f"Full error message: {e}\n" - f"{parsed_output_message}\n", + f"Parsed solver data: {parsed_output_data}\n", ) if ( config.raise_exception_on_nonoptimal_result @@ -648,8 +610,6 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] "alpha_pr", "ls", ] - numerical_columns = set(columns) - numerical_columns.remove('iter') iterations = [] n_expected_columns = len(columns) @@ -694,17 +654,11 @@ def _parse_ipopt_output(self, output: Union[str, io.StringIO]) -> Dict[str, Any] # Capture optional IPOPT diagnostic tags if present if extra_tokens: - if all(tok in _DIAGNOSTIC_TAGS for tok in extra_tokens): - iter_data['diagnostic_tags'] = "".join(extra_tokens) - else: - logger.warning( - f"Unrecognized Ipopt diagnostic tags {extra_tokens} on line: {line}" - ) + iter_data['diagnostic_tags'] = " ".join(extra_tokens) # Attempt to cast all values to float where possible - for key, val in iter_data.items(): - if key not in numerical_columns: - continue + for key in columns[1:]: + val = iter_data[key] if val == '-': iter_data[key] = None else: