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).