Solver Logging, Missed Output

[eslickj]

IDAES has a feature to log solver output (https://github.com/IDAES/idaes-pse/blob/901a97631e3b9c52ee6518ab377dd6cc10677201/idaes/logger.py#L311). The context manager uses Pyomo's capture_output() function to redirect stderr and stdout to a string stream. Then a seperate thread logs the solver output from the string stream.

In the context manager, if the solver exits with a non-zero exit code, Pyomo will raise an exception and the stop flag will be set on the logging thread. Once the stop flag is set, the last of the solver output will be read. In some cases, when the solver process exits with a nonzero code, somehow the logging thread will quit before the last of the solver output is captured.

The stop flag on the thread is set after the solver finishes and the subprocess exits, so all the solver output should be done by then. Once Pyomo catches that the solver failed and raises an exception the sliver process is done, but somehow the the output from the solver process doesn't make it to the string stream before the thread quits even though the subprocess for the solver is done. I tried to flush the stream before the final read, but that didn't work. Delaying the final read works, but it isn't a really solid solution see PR #887. There must be some other asynchonous stuff between Pyomo, subprocess, capture_output and string streams.

We should merge #887, but we should think about whether there is a more solid solution.

This probably isn't very clear, but I think I understand the problem reasonably well, so I can elaborate or clarify the description. @dallan-keylogic is able to reproduce the error with the PETSc solver, so it may also have to do with PETSc or our wrapper producing output in a slightly weird way.

[andrewlee94]

This should have been addressed in #1098