lbianchi-lbl
commented
1 year ago Running the failing test with the --pdb flag:
================================================ test session starts =================================================
platform linux -- Python 3.8.15, pytest-7.2.0, pluggy-1.0.0 -- /opt/conda/envs/test-dispatches-164/bin/python
cachedir: .pytest_cache
rootdir: /home/ludo/lbl/dispatches/test-164/idaes-pse, configfile: pytest.ini
plugins: cov-4.0.0, anyio-3.6.2, nbval-0.9.6
collected 110 items / 109 deselected / 1 selected
case_studies/fossil_case/ultra_supercritical_plant/storage/tests/test_discharge_usc_powerplant.py::test_main_function <- ../../dispatches/dispatches/case_studies/fossil_case/ultra_supercritical_plant/storage/tests/test_discharge_usc_powerplant.py 2022-12-02 12:18:40 [INFO] idaes.init.fs.boiler.control_volume: Initialization Complete
2022-12-02 12:18:40 [INFO] idaes.init.fs.boiler: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:40 [INFO] idaes.init.fs.turbine_splitter[1]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:40 [INFO] idaes.init.fs.turbine_splitter[2]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:40 [INFO] idaes.init.fs.reheater[1].control_volume: Initialization Complete
2022-12-02 12:18:40 [INFO] idaes.init.fs.reheater[1]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:41 [INFO] idaes.init.fs.turbine_splitter[3]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:41 [INFO] idaes.init.fs.turbine_splitter[4]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:41 [INFO] idaes.init.fs.reheater[2].control_volume: Initialization Complete
2022-12-02 12:18:41 [INFO] idaes.init.fs.reheater[2]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:41 [INFO] idaes.init.fs.turbine_splitter[5]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:41 [INFO] idaes.init.fs.turbine_splitter[6]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:41 [INFO] idaes.init.fs.turbine_splitter[7]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:41 [INFO] idaes.init.fs.turbine_splitter[8]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:41 [INFO] idaes.init.fs.turbine_splitter[9]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:41 [INFO] idaes.init.fs.turbine_splitter[10]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:42 [INFO] idaes.init.fs.condenser_mix: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:42 [INFO] idaes.init.fs.condenser.control_volume: Initialization Complete
2022-12-02 12:18:42 [INFO] idaes.init.fs.condenser: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh_mixer[1]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[1].hot_side: Initialization Complete
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[1].cold_side: Initialization Complete
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[1]: Initialization Completed, optimal - Optimal Solution Found
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh_mixer[2]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[2].hot_side: Initialization Complete
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[2].cold_side: Initialization Complete
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[2]: Initialization Completed, optimal - Optimal Solution Found
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh_mixer[3]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[3].hot_side: Initialization Complete
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[3].cold_side: Initialization Complete
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[3]: Initialization Completed, optimal - Optimal Solution Found
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh_mixer[4]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[4].hot_side: Initialization Complete
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[4].cold_side: Initialization Complete
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[4]: Initialization Completed, optimal - Optimal Solution Found
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[5].hot_side: Initialization Complete
2022-12-02 12:18:42 [INFO] idaes.init.fs.fwh[5].cold_side: Initialization Complete
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh[5]: Initialization Completed, optimal - Optimal Solution Found
2022-12-02 12:18:43 [INFO] idaes.init.fs.deaerator: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh_mixer[6]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh[6].hot_side: Initialization Complete
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh[6].cold_side: Initialization Complete
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh[6]: Initialization Completed, optimal - Optimal Solution Found
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh_mixer[7]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh[7].hot_side: Initialization Complete
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh[7].cold_side: Initialization Complete
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh[7]: Initialization Completed, optimal - Optimal Solution Found
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh_mixer[8]: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh[8].hot_side: Initialization Complete
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh[8].cold_side: Initialization Complete
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh[8]: Initialization Completed, optimal - Optimal Solution Found
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh[9].hot_side: Initialization Complete
2022-12-02 12:18:43 [INFO] idaes.init.fs.fwh[9].cold_side: Initialization Complete
2022-12-02 12:18:44 [INFO] idaes.init.fs.fwh[9]: Initialization Completed, optimal - Optimal Solution Found
Model Initialization = optimal
******************* USC Model Initialized ********************
2022-12-02 12:18:46 [INFO] idaes.init.fs.discharge.es_split: Initialization Complete: optimal - Optimal Solution Found
2022-12-02 12:18:46 [INFO] idaes.init.dispatches.properties.solarsalt_properties: fs.discharge.hxd.hot_side.properties_in Initialisation Step 1 Complete.
2022-12-02 12:18:46 [INFO] idaes.init.dispatches.properties.solarsalt_properties: Initialization Step 1 Complete.
2022-12-02 12:18:46 [INFO] idaes.init.dispatches.properties.solarsalt_properties: fs.discharge.hxd.hot_side.properties_out Initialisation Step 1 Complete.
2022-12-02 12:18:46 [INFO] idaes.init.dispatches.properties.solarsalt_properties: Initialization Step 1 Complete.
2022-12-02 12:18:46 [INFO] idaes.init.dispatches.properties.solarsalt_properties: State Released.
2022-12-02 12:18:46 [INFO] idaes.init.fs.discharge.hxd.hot_side: Initialization Complete
2022-12-02 12:18:46 [INFO] idaes.init.fs.discharge.hxd.cold_side: Initialization Complete
2022-12-02 12:18:46 [INFO] idaes.init.dispatches.properties.solarsalt_properties: State Released.
2022-12-02 12:18:46 [INFO] idaes.init.fs.discharge.hxd: Initialization Completed, optimal - Optimal Solution Found
Discharge model initialization solver termination: optimal
************* Discharge Model Initialized ******************
Cost initialization solver termination: optimal
******************** Costing Initialized *************************
Starting GDPopt version 22.5.13 using LOA algorithm
iterlim: None
time_limit: None
tee: true
logger: <Logger pyomo.contrib.gdpopt (INFO)>
init_strategy: None
init_algorithm: no_init
custom_init_disjuncts: []
max_slack: 1000.0
OA_penalty_factor: 1000.0
set_cover_iterlim: 8
discrete_problem_transformation: gdp.bigm
call_before_discrete_problem_solve: !!python/name:pyomo.contrib.gdpopt.util._DoNothing ''
call_after_discrete_problem_solve: !!python/name:pyomo.contrib.gdpopt.util._DoNothing ''
call_before_master_solve: !!python/name:pyomo.contrib.gdpopt.util._DoNothing ''
call_after_master_solve: !!python/name:pyomo.contrib.gdpopt.util._DoNothing ''
subproblem_initialization_method: <function restore_vars_to_original_values at 0x7f76d8341670>
call_before_subproblem_solve: !!python/name:pyomo.contrib.gdpopt.util._DoNothing ''
call_after_subproblem_solve: <function print_model at 0x7f76ba1785e0>
call_after_subproblem_feasible: !!python/name:pyomo.contrib.gdpopt.util._DoNothing ''
round_discrete_vars: true
force_subproblem_nlp: false
mip_presolve: true
subproblem_presolve: true
max_fbbt_iterations: 3
tighten_nlp_var_bounds: false
calc_disjunctive_bounds: false
obbt_disjunctive_bounds: false
mip_solver: cbc
mip_solver_args:
nlp_solver: ipopt
nlp_solver_args:
options: {max_iter: 150}
tee: true
minlp_solver: baron
minlp_solver_args:
local_minlp_solver: bonmin
local_minlp_solver_args:
bound_tolerance: 1.0e-06
small_dual_tolerance: 1.0e-08
integer_tolerance: 1.0e-05
constraint_tolerance: 1.0e-06
variable_tolerance: 1.0e-08
zero_tolerance: 1.0e-15
If you use this software, you may cite the following:
- Implementation:
Chen, Q; Johnson, ES; Bernal, DE; Valentin, R; Kale, S;
Bates, J; Siirola, JD; Grossmann, IE.
Pyomo.GDP: an ecosystem for logic based modeling and optimization
development.
Optimization and Engineering, 2021.
Original model has 630 constraints (153 nonlinear) and 1 disjunctions, with 565 variables, of which 5 are binary, 0 are integer, and 560 are continuous.
---Starting GDPopt initialization---
Finished discrete problem initialization in 4.57s and 0 iterations
=============================================================================================
Iteration | Subproblem Type | Lower Bound | Upper Bound | Gap | Time(s)
1 discrete 0.00000 inf nan% 9.45
Solved in 1 iterations and 9.75593 seconds
Optimal objective value inf
Relative optimality gap nan%
No feasible solutions found.
FAILED
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> captured log >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
WARNING pyomo.core:PyomoModel.py:209 Loading a SolverResults object with a warning status into model.name="fs.discharge.es_turbine";
- termination condition: other
- message from solver: Too few degrees of freedom (rethrown)!
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> traceback >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
@pytest.mark.gdpopt
@pytest.mark.integration
def test_main_function():
# Build ultra-supercritical plant base model
m_usc = usc.build_plant_model()
# Initialize ultra-supercritical plant base model
usc.initialize(m_usc)
# Build discharge model
m = discharge_usc.main(m_usc, solver=solver, optarg=optarg)
discharge_usc.model_analysis(m, heat_duty=heat_duty)
# Solve model using GDPopt
> results = discharge_usc.run_gdp(m)
../../dispatches/dispatches/case_studies/fossil_case/ultra_supercritical_plant/storage/tests/test_discharge_usc_powerplant.py:86:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
../../dispatches/dispatches/case_studies/fossil_case/ultra_supercritical_plant/storage/discharge_design_ultra_supercritical_power_plant.py:1181: in run_gdp
results = opt.solve(
../pyomo/pyomo/contrib/gdpopt/GDPopt.py:133: in solve
return SolverFactory(
../pyomo/pyomo/contrib/gdpopt/algorithm_base_class.py:119: in solve
self._solve_gdp(model, config)
../pyomo/pyomo/contrib/gdpopt/loa.py:108: in _solve_gdp
self._fix_discrete_soln_solve_subproblem_and_add_cuts(
../pyomo/pyomo/contrib/gdpopt/oa_algorithm_utils.py:25: in _fix_discrete_soln_solve_subproblem_and_add_cuts
nlp_termination = solve_subproblem(subprob_util_block, self,
../pyomo/pyomo/contrib/gdpopt/solve_subproblem.py:342: in solve_subproblem
with preprocess_subproblem(subprob_util_block, config) as call_solver:
../pyomo/pyomo/contrib/gdpopt/solve_subproblem.py:238: in __enter__
fbbt(m, integer_tol=self.config.integer_tolerance,
../pyomo/pyomo/contrib/fbbt/fbbt.py:1519: in fbbt
_new_var_bounds = _fbbt_block(comp, config)
../pyomo/pyomo/contrib/fbbt/fbbt.py:1416: in _fbbt_block
_new_var_bounds = _fbbt_con(c, config)
../pyomo/pyomo/contrib/fbbt/fbbt.py:1345: in _fbbt_con
visitorB.dfs_postorder_stack(con.body)
../pyomo/pyomo/core/expr/visitor.py:880: in dfs_postorder_stack
flag, value = self.visiting_potential_leaf(_sub)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <pyomo.contrib.fbbt.fbbt._FBBTVisitorRootToLeaf object at 0x7f76d2c5dac0>, node = 'H2O'
def visiting_potential_leaf(self, node):
if node.__class__ in nonpyomo_leaf_types:
lb, ub = self.bnds_dict[node]
> if abs(lb - value(node)) > self.feasibility_tol:
E TypeError: unsupported operand type(s) for -: 'str' and 'str'
../pyomo/pyomo/contrib/fbbt/fbbt.py:1195: TypeError
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> entering PDB >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> PDB post_mortem >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
> /home/ludo/lbl/dispatches/test-164/pyomo/pyomo/contrib/fbbt/fbbt.py(1195)visiting_potential_leaf()
-> if abs(lb - value(node)) > self.feasibility_tol:
(Pdb) node
'H2O'
(Pdb) lb
'H2O'
(Pdb) u
> /home/ludo/lbl/dispatches/test-164/pyomo/pyomo/core/expr/visitor.py(880)dfs_postorder_stack()
-> flag, value = self.visiting_potential_leaf(_sub)
(Pdb) _dub
*** NameError: name '_dub' is not defined
(Pdb) _sub
'H2O'
(Pdb) u
> /home/ludo/lbl/dispatches/test-164/pyomo/pyomo/contrib/fbbt/fbbt.py(1345)_fbbt_con()
-> visitorB.dfs_postorder_stack(con.body)
(Pdb) con
<pyomo.core.base.constraint._GeneralConstraintData object at 0x7f76ea3bba60>
(Pdb) dir(con)
['_PPRINT_INDENT', '__call__', '__class__', '__deepcopy__', '__delattr__', '__dir__', '__doc__', '__eq__', '__format__', '__ge__', '__getattribute__', '__getstate__', '__gt__', '__hash__', '__init__', '__init_subclass__', '__le__', '__lt__', '__module__', '__ne__', '__new__', '__pickle_slots__', '__reduce__', '__reduce_ex__', '__repr__', '__setattr__', '__setstate__', '__sizeof__', '__slots__', '__str__', '__subclasshook__', '__weakref__', '_active', '_body', '_component', '_create_objects_for_deepcopy', '_expr', '_index', '_lb', '_linear_canonical_form', '_lower', '_populate_deepcopied_object', '_pprint_base_impl', '_ub', '_upper', 'activate', 'active', 'body', 'clear_suffix_value', 'cname', 'ctype', 'deactivate', 'equality', 'expr', 'get_suffix_value', 'get_value', 'getname', 'has_lb', 'has_ub', 'index', 'is_component_type', 'is_expression_type', 'is_indexed', 'is_logical_type', 'is_named_expression_type', 'is_numeric_type', 'is_parameter_type', 'is_reference', 'is_variable_type', 'lb', 'local_name', 'lower', 'lslack', 'model', 'name', 'parent_block', 'parent_component', 'pprint', 'set_suffix_value', 'set_value', 'slack', 'strict_lower', 'strict_upper', 'type', 'ub', 'upper', 'uslack']
(Pdb) con.expr
<pyomo.core.expr.logical_expr.EqualityExpression object at 0x7f76c6503490>
(Pdb) str(con)
'fs.bfp.eq_work[0.0]'
(Pdb)
This is one of the test failures observed in #161.
Running
git bisectin theidaes-pserepo, between the commits:points to this commit: https://github.com/IDAES/idaes-pse/commit/bf61436a82e3878400d9db4dbf954b10426d1080