Several examples tests failing

[eslickj]

There are some examples test failing. I'm having a hard time sorting out what's failing and how, but I suspect it may have something to do with the doc reorg or updating the Pyomo version. Not sure who to assign this too, so we can try to update that later.

From doc build:

docs_test/Examples/Tools/degeneracy_hunter.rst:234: ERROR: Undefined substitution referenced: "residual".
docs_test/Examples/Tools/degeneracy_hunter.rst:234: ERROR: Undefined substitution referenced: "residual".
docs_test/Examples/Tools/degeneracy_hunter.rst:409: ERROR: Undefined substitution referenced: "residual".
docs_test/Examples/Tools/degeneracy_hunter.rst:409: ERROR: Undefined substitution referenced: "residual".
docs_test/Examples/Tools/degeneracy_hunter.rst:409: ERROR: Undefined substitution referenced: "residual".
docs_test/Examples/Tools/degeneracy_hunter.rst:712: ERROR: Undefined substitution referenced: "residual".
docs_test/Examples/Tools/degeneracy_hunter.rst:712: ERROR: Undefined substitution referenced: "residual".

docs_test/Examples/Tools/data_management_framework.rst:514: ERROR: Unknown target name: "id".
docs_test/Examples/Tools/data_management_framework.rst:576: ERROR: Unknown target name: "id".

docs_test/Examples/SurrMod/PySMO/PySMO_basics.rst:378: ERROR: Unknown target name: "x".
docs_test/Examples/SurrMod/PySMO/PySMO_basics.rst:378: ERROR: Unknown target name: "x".
docs_test/Examples/SurrMod/PySMO/PySMO_basics.rst:378: ERROR: Unknown target name: "x".
docs_test/Examples/SurrMod/PySMO/PySMO_basics.rst:378: ERROR: Unknown target name: "x".
docs_test/Examples/SurrMod/PySMO/PySMO_basics.rst:378: ERROR: Unknown target name: "x".
docs_test/Examples/SurrMod/PySMO/PySMO_basics.rst:378: ERROR: Unknown target name: "x".
docs_test/Examples/SurrMod/PySMO/PySMO_basics.rst:378: ERROR: Unknown target name: "x".

TypeError: object NoneType can't be used in 'await' expression
2022-02-14 17:52:01,553 ERROR - [Worker 0] Notebook execution failed: execution error for '/tmp/tmpfbxogeg6/air_separation_case_study.ipynb': An error occurred while executing the following cell:
------------------
m.fs.M101.initialize(outlvl=idaeslog.INFO_LOW) 
propagate_state(m.fs.s01)
m.fs.F101.initialize(outlvl=idaeslog.INFO_LOW)
------------------

---------------------------------------------------------------------------
InitializationError                       Traceback (most recent call last)
/tmp/ipykernel_3865/2171148868.py in <module>
      1 m.fs.M101.initialize(outlvl=idaeslog.INFO_LOW)
      2 propagate_state(m.fs.s01)
----> 3 m.fs.F101.initialize(outlvl=idaeslog.INFO_LOW)

/usr/share/miniconda/envs/examples-pse-dev/lib/python3.8/site-packages/idaes/core/unit_model.py in initialize(blk, state_args, outlvl, solver, optarg)
    659 
    660         if not check_optimal_termination(results):
--> 661             raise InitializationError(
    662                 f"{blk.name} failed to initialize successfully. Please check "
    663                 f"the output logs for more information.")

 2022-02-14 18:25:50,515 DEBUG - Waiting for 1 processes to finish
2022-02-14 18:26:51,519 DEBUG - Waiting for 1 processes to finish
2022-02-14 18:27:22,356 ERROR - [Worker 0] Failed to convert D:\a\examples-pse\examples-pse\src\Examples\Advanced\CustomProperties\Hydrocarbon_Processing_example.ipynb: timeout for 'C:\Users\RUNNER~1\AppData\Local\Temp\tmprw3iry3j\Hydrocarbon_Processing_example.ipynb': 1280.1595520973206s > 600s

[lbianchi-lbl]

I'm looking into the failing jobs, and it seems that there are a few issues but nothing that strikes me as an obvious cause:

• Dependencies: comparing the same job combination (OS/Python version) for failing and passing runs, the output of conda list looks almost identical, and nothing that could point to an update to one of the dependencies breaking things
• Pyomo version: this is being updated in Update prerelease requirement for Pyomo to 6.3 idaes-pse#703, which is not merged yet, so this cannot be the difference
• The docs reorg (assuming this refers to Full Docs Diataxis Re-Org idaes-pse#689) only affects the idaes-pse docs. The docs in examples-pse should be completely independent from those, so I don't think this would cause these errors

The errors in the notebook are familiar issues that we thought had been solved:

• air_separation_case_study failing initialization:

    2022-02-14 05:39:35,082 ERROR - [Worker 0] Notebook execution failed: execution error for '/tmp/tmpi0_jo4wy/air_separation_case_study.ipynb': An error occurred while executing the following cell:
------------------
m.fs.M101.initialize(outlvl=idaeslog.INFO_LOW) 
propagate_state(m.fs.s01)
m.fs.F101.initialize(outlvl=idaeslog.INFO_LOW)
------------------

---------------------------------------------------------------------------
InitializationError                       Traceback (most recent call last)
/tmp/ipykernel_3958/2171148868.py in <module>
      1 m.fs.M101.initialize(outlvl=idaeslog.INFO_LOW)
      2 propagate_state(m.fs.s01)
----> 3 m.fs.F101.initialize(outlvl=idaeslog.INFO_LOW)

/usr/share/miniconda/envs/examples-pse-dev/lib/python3.7/site-packages/idaes/core/unit_model.py in initialize(blk, state_args, outlvl, solver, optarg)
    660         if not check_optimal_termination(results):
    661             raise InitializationError(
--> 662                 f"{blk.name} failed to initialize successfully. Please check "
    663                 f"the output logs for more information.")
    664 

InitializationError: fs.F101 failed to initialize successfully. Please check the output logs for more information.

• air_separation_case_study exceeding timeout

2022-02-14 06:02:46,965 ERROR - [Worker 0] Failed to convert D:\a\examples-pse\examples-pse\src\Examples\Advanced\CustomProperties\air_separation_case_study.ipynb: timeout for 'C:\Users\RUNNER~1\AppData\Local\Temp\tmphhfcsnd4\air_separation_case_study.ipynb': 1275.5258157253265s > 600s
2022-02-14 06:02:46,989 INFO - [Worker 0] Convert notebook name=D:\a\examples-pse\examples-pse\src\Examples\Advanced\CustomProperties\air_separation_case_study.ipynb: end, ok=False duration=1276.5s

• Both air_separation_case_study and HDA exceeding timeout:

 2022-02-14 06:47:39,228 ERROR - [Worker 0] Failed to convert D:\a\examples-pse\examples-pse\src\Examples\Advanced\CustomProperties\air_separation_case_study.ipynb: timeout for 'C:\Users\RUNNER~1\AppData\Local\Temp\tmp8698d5ci\air_separation_case_study.ipynb': 1272.8482093811035s > 600s

2022-02-14 07:00:40,709 ERROR - [Worker 0] Failed to convert D:\a\examples-pse\examples-pse\src\Examples\Advanced\CustomProperties\Hydrocarbon_Processing_example.ipynb: timeout for 'C:\Users\RUNNER~1\AppData\Local\Temp\tmp8698d5ci\Hydrocarbon_Processing_example.ipynb': 757.2173094749451s > 600s

[lbianchi-lbl]

One other possibility is that something changed in idaes-pse between the last passing and first failing nighty runs. The last passing run was last Thursday, Feb 11th; looking at https://github.com/IDAES/idaes-pse/commits, it seems that one of these PRs (or the combined effect of any of them) could be the cause of the errors:

• Switch cubic EOS extrernal functions to generic cubic root, and move some expression back to pyomo  idaes-pse#704
• Remove pywin32 version constraint needed for #258 idaes-pse#707
• Fixing string checking of Expressions idaes-pse#708

Since there's only three of them and they have been squash-merged, it should be possible to run the CI jobs in this repo after checking out each commit in parallel. I'll try to open a PR with these changes and see if that's enough to pinpoint a single breaking commit.

[andrewlee94]

I can't see how PR 708 would be the cause. It is possible that 704 caused some unexpected change, but even that should have been transparent to the examples.

[lbianchi-lbl]

@andrewlee94 I agree, I don't have a clue on what it could be. The remaining one, #707, could in principle result in changes to the Jupyter notebook infrastructure, but (a) it only applies to Windows (while failing jobs occur on both Linux and Windows), and (b) even then, I don't see how it could be related to the initialization error. Let's see if the brute force debugging in #97 can shed some light on this.

[eslickj]

708 should technically not have changed anything, but it changed the way an expression was written. If a problem is that delicate, it was borderline broken already. I don't really understand how the examples tests work. Don't they run on the idase-pse PRs?

[lbianchi-lbl]

@eslickj Do you mean IDAES/idaes-pse#704? IDAES/idaes-pse#708 only changed test files, so that wouldn't have any influence on this repo.

As part of the extended/integration CI checks, a subset of the examples are run. This is defined within the idaes-pse repository here: https://github.com/IDAES/idaes-pse/blob/main/.github/actions/run-examples/build-config-for-idaes-ci.yml, rather than using the default configuration in examples-pse: this is a conscious choice to reduce the influence of "hidden state" on the idaes-pse tests, which makes failures hard to detect.

More specifically, the reason why the two "problem child" examples air_separation_case_study and Hydrocarbon_Processing_example were not included in the idaes-pse CI checks is precisely because they (a) take a long time to run, and (b) are very fragile since (at least to my recollection) seem to have been the cause of the majority of the example failed runs. This unfortunately looks to me like a Catch-22 of sort: their sensitivity to changes in the IDAES codebase make them a good "regression canary", but the fact that they often fail for other reasons (e.g. OS-specific solver issues) make them too unreliable to be used as part of the PR checks.

---

If you look at https://github.com/IDAES/examples-pse/actions/runs/1845041970 (where the Git commit hashes are the 4 latest commits on idaes-pse main, see https://github.com/IDAES/idaes-pse/commits), it looks like IDAES/idaes-pse#704 (hash 747b6df) is when the tests start breaking. Some of the failures seem to be non-deterministic (each OS/Python version/hash combination is run 4 times to account for that), probably because of the fixed timeout threshold, but to me it looks like the breaking change happened between c7061 and 747b6).

[andrewlee94]

@lbianchi-lbl @eslickj Well, in some ways it does not surprise me that that commit is what broke everything, even though it really should not. As John said: " If a problem is that delicate, it was borderline broken already".

We really need someone to get in there and fix those up properly - I am fairly certain they do not use the scaling tools. I think someone was already working on one of them from a previous round of them failing.

[lbianchi-lbl]

@andrewlee94 From a quick search, the latest issues about these notebooks are #81 for Hydrocarbon_Processing_example, and #77 and #89 for air_separation_case_study. I definitely agree that we should make it a priority to fix these issues once and for all, as the firefighting due to these reoccurring errors ends up being a huge time sink.

[andrewlee94]

Ah, #89 was the one I was thinking of and it was related to a different model (the HDA case study). Hopefully the same approach that was applied there can fix these issues (once and for all).

[lbianchi-lbl]

@andrewlee94 ah, I see, I mistakenly thought that #89 was about air_separation_case_study when it was actually about HDA_flowsheet_with_distillation, a different notebook altogether.

If I understand correctly what you're saying, this is (or could be) good news, since it means that the fix for HDA_flowsheet_with_distillation did work to address the problem (at least for this particular set of failures triggered by IDAES/idaes-pse#704), and the hope is to try to apply an equivalent fix to air_separation_case_study and Hydrocarbon_Processing_example.

[andrewlee94]

@lbianchi-lbl I hope so at least - my most likely guess for the cause of failure here is poor scaling, which is the same problem the HDA Flowsheet had.

[eslickj]

@lbianchi-lbl, the change in 708 was this...

Originally we had a function that was root(eos_type, A, B). That found a real root of a cubic equation. 708 results in the same thing but looks like this root(b(eos_type, A, B), c(eos_type, A, B), d(eos_type, A, B)) where b, c, d are just Pyomo expressions. The resulting expression should be functionally the same. I just moved a piece of the calculation from the external function back into Pyomo expressions. I'm really struggling to understand how it would break anything, but I guess it points to extreme delicateness of the models.

So it's more than just test changes. I just can't really see how it could affect anything. Everything about the new version should be the same, but it's not written exactly the same.

[bpaul4]

@lbianchi-lbl Scaling helped improve #81 but regenerating the initialization files greatly reduced the runtime and ultimately resolved the issue. The main obstacle is that it takes about an hour to regenerate the initialization file, so it is difficult to build a check into the CI client that wouldn't potentially regenerate the file many times on multiple PRs that time out.

In response to @eslickj , small solver or calculation changes could dramatically impact the quality of the initialization point - in #81 solving with IPOPT 3.12 using an initialization point trained using IPOPT 3.12 more than doubled the expected runtime; adding scaling reduced the notebook runtime from 650 to 550 CPU seconds, and then regenerating the initialization file using IPOPT 3.13 further reduced this to 30 CPU seconds.

[lbianchi-lbl]

@eslickj @bpaul4 I see, thanks for the clarifications. I'm wondering, how often do the initialization files need to be regenerated to provide this kind of runtime improvements? Or, in other words, what type of changes (e.g. to the model itself, IPOPT version, ...) require an initialization file to be regenerated? If regenerating the initialization files before each run is not necessary, we could think of some way of generating them separately from the PR runs (e.g. on schedule, weekly or as needed), and either commit them to the repository or fetch them before the notebook is run during the PR runs.

[eslickj]

The initialization files really need to be regenerated anytime anything changes. I know that doesn't really nail it down very well. Especially for ill-conditioned problems the solution may be sensitive to very small changes. A change could be as small as a new version some library like blas or lapack. A solver version or build change could do it. I'd hope that that sort of change would be too small to cause any issues, but sometimes it is a problem. The more obvious changes would be if the IDAES model structure changes so that a variable changes name or something. In that case most of the model would load, but not the variable with the changed name.

The nice thing about loading an initialization that's done is that it saves time. The problem is that it's easy for things to go wrong if anything changes. It doesn't help that we seem to have some models that are very sensitive to minor changes.

[lbianchi-lbl]

Hmm, I see. I mean, one fairly straightforward way to solve this would be to regenerate the initialization files daily, e.g. before the nightly checks, save the files as a workflow run artifact with GitHub Actions, and fetch that version when running the examples. As I understand, users can always recreate the initialization files by themselves (it just takes a while to run) if the daily built files are not available for whatever reason, so this would not risk making the examples significantly less usable outside of the CI context.

[andrewlee94]

In regards to regenerating the JSON initialization files, we should add functionality to the load from JSON function that will check that all variables were initialized that we can then use in our notebook testing to identify these issues. That however is a separate issue for now - our immediate concern is to get the notebooks fixed for the release.

[bpaul4]

I pulled the latest IDAES:main and EXAMPLES-PSE:main to my local Windows machine (Python 3.7) and pytest --verbose -m 'not unit' tests/ did not show any runtime errors. I opened and ran air_separation_case_study.ipynb on my machine as well and did not encounter any initialization errors. Since last night's test run did show these errors for several environments, I'll have to create a PR to test the CI jobs for a new HC init file and new AS scaling.

In addition to bad scaling in the AS notebook, I'm wondering if the value change commit in #83 is contributing to this behavior. The AS notebook does not currently serialize the initialization point, so I will just add scaling for now and see if this helps.

Update: RemovingHC_init.json.gz and attempting to regenerate the serialized model file threw an initialization error with the scaling we added to address #81. Setting the manual scaling factors to 1E0 first and then regenerating the file did not fail on this step, and is currently still running.

if not os.path.exists("HI_init.json.gz"):
    seq.run(m, function)
    
    # Solve the simulation using ipopt
    # Note: If the degrees of freedom = 0, we have a square problem
    solve_status = solver.solve(m, tee=True)

    ms.to_json(m, fname="HI_init.json.gz")
else:
    ms.from_json(m, fname="HI_init.json.gz")

2022-02-16 07:59:40 [INFO] idaes.init.fs.H101.control_volume.properties_in: Starting initialization
2022-02-16 07:59:40 [INFO] idaes.init.fs.H101.control_volume.properties_in: State variable initialization completed.
2022-02-16 07:59:40 [INFO] idaes.init.fs.H101.control_volume.properties_in: Property initialization: optimal - Optimal Solution Found.
2022-02-16 07:59:40 [INFO] idaes.init.fs.H101.control_volume.properties_out: Starting initialization
2022-02-16 07:59:40 [INFO] idaes.init.fs.H101.control_volume.properties_out: State variable initialization completed.
2022-02-16 07:59:40 [INFO] idaes.init.fs.H101.control_volume.properties_out: Property initialization: optimal - Optimal Solution Found.
2022-02-16 07:59:40 [INFO] idaes.init.fs.H101.control_volume.properties_out: State released.
2022-02-16 07:59:40 [INFO] idaes.init.fs.H101.control_volume: Initialization Complete
2022-02-16 07:59:40 [INFO] idaes.init.fs.H101: Initialization Step 1 Complete.
2022-02-16 07:59:46 [INFO] idaes.init.fs.H101: Initialization Step 2 optimal - Optimal Solution Found.
2022-02-16 07:59:46 [INFO] idaes.init.fs.H101.control_volume.properties_in: State released.
2022-02-16 07:59:46 [INFO] idaes.init.fs.H101: Initialization Complete: optimal - Optimal Solution Found
2022-02-16 07:59:46 [INFO] idaes.init.fs.R101.control_volume.properties_in: Starting initialization
2022-02-16 07:59:46 [INFO] idaes.init.fs.R101.control_volume.properties_in: State variable initialization completed.
2022-02-16 07:59:46 [INFO] idaes.init.fs.R101.control_volume.properties_in: Property initialization: optimal - Optimal Solution Found.
2022-02-16 07:59:46 [INFO] idaes.init.fs.R101.control_volume.properties_out: Starting initialization
2022-02-16 07:59:46 [INFO] idaes.init.fs.R101.control_volume.properties_out: State variable initialization completed.
2022-02-16 07:59:46 [INFO] idaes.init.fs.R101.control_volume.properties_out: Property initialization: optimal - Optimal Solution Found.
2022-02-16 07:59:46 [INFO] idaes.init.fs.R101.control_volume.properties_out: State released.
2022-02-16 07:59:46 [INFO] idaes.init.fs.R101.control_volume: Initialization Complete
2022-02-16 07:59:46 [INFO] idaes.init.fs.R101: Initialization Step 1 Complete.
2022-02-16 08:00:32 [INFO] idaes.init.fs.R101: Initialization Step 2 infeasible - Converged to a locally infeasible point. Problem may be infeasible..
2022-02-16 08:00:32 [INFO] idaes.init.fs.R101.control_volume.properties_in: State released.

---------------------------------------------------------------------------
InitializationError                       Traceback (most recent call last)
(other output between these lines......)
InitializationError: fs.R101 failed to initialize successfully. Please check the output logs for more information.

[bpaul4]

The HC notebook with scaling factors changed to 1E0 ran through the initialization for more than two hours, and then ultimately failed on the Flash unit (it only took 20 minutes to initialize everything pre-Flash, the rest was this unit). The notebook with scaling failed even earlier (on the Reactor unit), and based on this message I'm suspecting that the property packages may be decreasing the solvability of these flowsheets:

2022-02-16 08:16:23 [INFO] idaes.init.fs.H101.control_volume.properties_in: Starting initialization
2022-02-16 08:16:23 [INFO] idaes.init.fs.H101.control_volume.properties_in: State variable initialization completed.
2022-02-16 08:16:23 [INFO] idaes.init.fs.H101.control_volume.properties_in: Property initialization: optimal - Optimal Solution Found.
2022-02-16 08:16:23 [INFO] idaes.init.fs.H101.control_volume.properties_out: Starting initialization
2022-02-16 08:16:24 [INFO] idaes.init.fs.H101.control_volume.properties_out: State variable initialization completed.
2022-02-16 08:16:24 [INFO] idaes.init.fs.H101.control_volume.properties_out: Property initialization: optimal - Optimal Solution Found.
2022-02-16 08:16:24 [INFO] idaes.init.fs.H101.control_volume.properties_out: State released.
2022-02-16 08:16:24 [INFO] idaes.init.fs.H101.control_volume: Initialization Complete
2022-02-16 08:16:24 [INFO] idaes.init.fs.H101: Initialization Step 1 Complete.
2022-02-16 08:16:29 [INFO] idaes.init.fs.H101: Initialization Step 2 optimal - Optimal Solution Found.
2022-02-16 08:16:29 [INFO] idaes.init.fs.H101.control_volume.properties_in: State released.
2022-02-16 08:16:29 [INFO] idaes.init.fs.H101: Initialization Complete: optimal - Optimal Solution Found
2022-02-16 08:16:29 [INFO] idaes.init.fs.R101.control_volume.properties_in: Starting initialization
2022-02-16 08:16:29 [INFO] idaes.init.fs.R101.control_volume.properties_in: State variable initialization completed.
2022-02-16 08:16:29 [INFO] idaes.init.fs.R101.control_volume.properties_in: Property initialization: optimal - Optimal Solution Found.
2022-02-16 08:16:29 [INFO] idaes.init.fs.R101.control_volume.properties_out: Starting initialization
2022-02-16 08:16:29 [INFO] idaes.init.fs.R101.control_volume.properties_out: State variable initialization completed.
2022-02-16 08:16:29 [INFO] idaes.init.fs.R101.control_volume.properties_out: Property initialization: optimal - Optimal Solution Found.
2022-02-16 08:16:29 [INFO] idaes.init.fs.R101.control_volume.properties_out: State released.
2022-02-16 08:16:29 [INFO] idaes.init.fs.R101.control_volume: Initialization Complete
2022-02-16 08:16:29 [INFO] idaes.init.fs.R101: Initialization Step 1 Complete.
2022-02-16 08:18:25 [INFO] idaes.init.fs.R101: Initialization Step 2 optimal - Optimal Solution Found.
2022-02-16 08:18:25 [INFO] idaes.init.fs.R101.control_volume.properties_in: State released.
2022-02-16 08:18:25 [INFO] idaes.init.fs.R101: Initialization Complete: optimal - Optimal Solution Found
2022-02-16 08:18:25 [INFO] idaes.init.fs.H102.control_volume.properties_in: Starting initialization
2022-02-16 08:20:22 [INFO] idaes.init.fs.H102.control_volume.properties_in: Dew and bubble point initialization: optimal - Optimal Solution Found.
2022-02-16 08:20:22 [INFO] idaes.init.fs.H102.control_volume.properties_in: Equilibrium temperature initialization completed.
2022-02-16 08:20:22 [INFO] idaes.init.fs.H102.control_volume.properties_in: State variable initialization completed.
2022-02-16 08:22:30 [INFO] idaes.init.fs.H102.control_volume.properties_in: Phase equilibrium initialization: optimal - Optimal Solution Found.
2022-02-16 08:24:31 [INFO] idaes.init.fs.H102.control_volume.properties_in: Property initialization: optimal - Optimal Solution Found.
2022-02-16 08:24:31 [INFO] idaes.init.fs.H102.control_volume.properties_out: Starting initialization
2022-02-16 08:26:10 [INFO] idaes.init.fs.H102.control_volume.properties_out: Dew and bubble point initialization: optimal - Optimal Solution Found.
2022-02-16 08:26:10 [INFO] idaes.init.fs.H102.control_volume.properties_out: Equilibrium temperature initialization completed.
2022-02-16 08:26:10 [INFO] idaes.init.fs.H102.control_volume.properties_out: State variable initialization completed.
2022-02-16 08:29:13 [INFO] idaes.init.fs.H102.control_volume.properties_out: Phase equilibrium initialization: optimal - Optimal Solution Found.
2022-02-16 08:31:14 [INFO] idaes.init.fs.H102.control_volume.properties_out: Property initialization: optimal - Optimal Solution Found.
2022-02-16 08:31:14 [INFO] idaes.init.fs.H102.control_volume.properties_out: State released.
2022-02-16 08:31:14 [INFO] idaes.init.fs.H102.control_volume: Initialization Complete
2022-02-16 08:31:14 [INFO] idaes.init.fs.H102: Initialization Step 1 Complete.
2022-02-16 08:35:09 [INFO] idaes.init.fs.H102: Initialization Step 2 optimal - Optimal Solution Found.
2022-02-16 08:35:09 [INFO] idaes.init.fs.H102.control_volume.properties_in: State released.
2022-02-16 08:35:09 [INFO] idaes.init.fs.H102: Initialization Complete: optimal - Optimal Solution Found
2022-02-16 08:35:09 [INFO] idaes.init.fs.F101.control_volume.properties_in: Starting initialization
2022-02-16 08:36:42 [INFO] idaes.init.fs.F101.control_volume.properties_in: Dew and bubble point initialization: optimal - Optimal Solution Found.
2022-02-16 08:36:42 [INFO] idaes.init.fs.F101.control_volume.properties_in: Equilibrium temperature initialization completed.
2022-02-16 08:36:42 [INFO] idaes.init.fs.F101.control_volume.properties_in: State variable initialization completed.
2022-02-16 08:39:36 [INFO] idaes.init.fs.F101.control_volume.properties_in: Phase equilibrium initialization: optimal - Optimal Solution Found.
2022-02-16 08:41:43 [INFO] idaes.init.fs.F101.control_volume.properties_in: Property initialization: optimal - Optimal Solution Found.
2022-02-16 08:41:43 [INFO] idaes.init.fs.F101.control_volume.properties_out: Starting initialization
2022-02-16 08:43:20 [INFO] idaes.init.fs.F101.control_volume.properties_out: Dew and bubble point initialization: optimal - Optimal Solution Found.
2022-02-16 08:43:20 [INFO] idaes.init.fs.F101.control_volume.properties_out: Equilibrium temperature initialization completed.
2022-02-16 08:43:20 [INFO] idaes.init.fs.F101.control_volume.properties_out: State variable initialization completed.

(the error output below appeared at 10:48)
---------------------------------------------------------------------------
ValueError                                Traceback (most recent call last)
~\AppData\Local\Temp/ipykernel_79836/1582686846.py in <module>
      1 if not os.path.exists("HI_init.json.gz"):
----> 2     seq.run(m, function)
      3 
      4     # Solve the simulation using ipopt
      5     # Note: If the degrees of freedom = 0, we have a square problem

c:\users\bpaul\miniconda3\lib\site-packages\pyomo\network\decomposition.py in run(self, model, function)
    284 
    285         try:
--> 286             return self._run_impl(model, function)
    287         finally:
    288             # Cleanup

c:\users\bpaul\miniconda3\lib\site-packages\pyomo\network\decomposition.py in _run_impl(self, model, function)
    306             logger.info("Starting first pass run of network")
    307             order = self.calculation_order(G)
--> 308             self.run_order(G, order, function, tset, use_guesses=True)
    309 
    310         if not self.options["solve_tears"] or not len(tset):

c:\users\bpaul\miniconda3\lib\site-packages\pyomo\network\decomposition.py in run_order(self, G, order, function, ignore, use_guesses)
    391                     self.load_values(port, default, fixed_ins, use_guesses)
    392 
--> 393                 function(unit)
    394 
    395                 # free the inputs that were not already fixed

~\AppData\Local\Temp/ipykernel_79836/1216033621.py in function(unit)
     17 
     18 def function(unit):
---> 19         unit.initialize(outlvl=idaeslog.INFO_HIGH)

c:\users\bpaul\github\idaes-pse\idaes\core\unit_model.py in initialize(blk, state_args, outlvl, solver, optarg)
    627         # ---------------------------------------------------------------------
    628         # Initialize control volume block
--> 629         flags = blk.control_volume.initialize(
    630             outlvl=outlvl,
    631             optarg=optarg,

c:\users\bpaul\github\idaes-pse\idaes\core\control_volume0d.py in initialize(blk, state_args, outlvl, optarg, solver, hold_state)
   1388             state_args=state_args,
   1389         )
-> 1390         out_flags = blk.properties_out.initialize(
   1391             outlvl=outlvl,
   1392             optarg=optarg,

c:\users\bpaul\github\idaes-pse\idaes\generic_models\properties\core\generic\generic_property.py in initialize(blk, state_args, state_vars_fixed, hold_state, outlvl, solver, optarg)
   1356         if n_cons > 0 and not skip:
   1357             with idaeslog.solver_log(solve_log, idaeslog.DEBUG) as slc:
-> 1358                 res = solve_indexed_blocks(opt, [blk], tee=slc.tee)
   1359             init_log.info(
   1360                 "Phase equilibrium initialization: {}.".format(

c:\users\bpaul\github\idaes-pse\idaes\core\util\initialization.py in solve_indexed_blocks(solver, blocks, **kwds)
    248 
    249         # Solve temporary Block
--> 250         results = solver.solve(tmp, **kwds)
    251 
    252     finally:

c:\users\bpaul\miniconda3\lib\site-packages\pyomo\opt\base\solvers.py in solve(self, *args, **kwds)
    624                 else:
    625                     if self._load_solutions:
--> 626                         _model.solutions.load_from(
    627                             result,
    628                             select=self._select_index,

c:\users\bpaul\miniconda3\lib\site-packages\pyomo\core\base\PyomoModel.py in load_from(self, results, allow_consistent_values_for_fixed_vars, comparison_tolerance_for_fixed_vars, ignore_invalid_labels, id, delete_symbol_map, clear, default_variable_value, select, ignore_fixed_vars)
    222                     "an 'aborted' status, but containing a solution")
    223             else:
--> 224                 raise ValueError("Cannot load a SolverResults object "
    225                                  "with bad status: %s"
    226                                  % str(results.solver.status))

ValueError: Cannot load a SolverResults object with bad status: error

[bpaul4]

The HC notebook is having difficulty re-initializing the Flash unit, and fails in restoration while solving the outlet control volume properties. I updated the scaling on both the AS and HC notebooks and pushed them to the PR referenced above to test the CI jobs, keeping the old HC init file for now since the notebook fails to generate a new one.

[lbianchi-lbl]

@bpaul4 thanks a lot for looking into that. I'm aware I'm not much use when dealing with this type of domain-specific issues, but let me know if there's anything I can do to help on the software/CI side of things.

[andrewlee94]

Closing this ,as no-one can remember what he actual issue was.