Skip to content

Log workflow output - #14301

Open
erlenlh wants to merge 10 commits into
mainfrom
log-workflow-output
Open

Log workflow output#14301
erlenlh wants to merge 10 commits into
mainfrom
log-workflow-output

Conversation

@erlenlh

@erlenlh erlenlh commented Aug 27, 2026

Copy link
Copy Markdown
Contributor

Issue
Part of #13320
Closes #14308

Approach
First of two PRs splitting the original "Store workflow output" work. This one
covers capturing workflow job output and writing it to the ERT log; the
follow-up (#14062) adds the
WorkflowEvent and persists events to experiment storage.

Workflow job output previously only reached the terminal ERT was started from,
so it was lost once that terminal was gone, and a job run outside a terminal
left no record at all.

  • Replaces sys.stdout/sys.stderr with a thread-aware _CaptureProxy while a
    job runs, recording what the calling thread writes while still forwarding it
    to the real stream. Concurrently running jobs do not pick up each other's
    output.
  • Adds WorkflowJobResult, recording name, index, arguments, output, status and
    timestamp per invocation. workflowReport() is keyed by job name, so a
    workflow running the same job twice previously kept only the last invocation's
    output.
  • Names workflows after their LOAD_WORKFLOW alias, so reporting can use the
    name users recognise rather than the source file path.
  • Writes one log entry per job invocation, naming the hook, workflow and job.
    Covers hooked workflows, ert workflow and the GUI Run workflow tool, since
    all three go through WorkflowRunner.

Also fixes two latent bugs found along the way: the running flag was not cleared
when a job was rejected for bad arguments, and a job that stopped the workflow
had its output dropped before it could be recorded.

  • PR title captures the intent of the changes, and is fitting for release notes.
  • Added appropriate release note label
  • Commit history is consistent and clean, in line with the contribution guidelines.
  • Make sure unit tests pass locally after every commit (git rebase -i main --exec 'just rapid-tests')

When applicable

  • When screenshots are changed: Review screenshot-PR in ert-testdata,
    merge screenshot-PR in ert-testdata before merging this PR.
  • When there are user facing changes: Updated documentation
  • New behavior or changes to existing untested code: Ensured that unit tests are added (See Ground Rules).
  • Large PR: Prepare changes in small commits for more convenient review
  • Bug fix: Add regression test for the bug
  • Bug fix: Add backport label to latest release (format: 'backport release-branch-name')

@erlenlh erlenlh mentioned this pull request Aug 27, 2026
10 tasks
@codecov-commenter

codecov-commenter commented Aug 27, 2026

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 98.36066% with 3 lines in your changes missing coverage. Please review.
✅ Project coverage is 91.77%. Comparing base (36be1f6) to head (5682c06).
⚠️ Report is 2 commits behind head on main.
✅ All tests successful. No failed tests found.

Files with missing lines Patch % Lines
src/ert/config/_capture_output.py 96.05% 3 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##             main   #14301      +/-   ##
==========================================
+ Coverage   91.75%   91.77%   +0.01%     
==========================================
  Files         485      486       +1     
  Lines       34700    34849     +149     
==========================================
+ Hits        31840    31983     +143     
- Misses       2860     2866       +6     
Flag Coverage Δ
cli-tests 35.90% <89.61%> (+0.22%) ⬆️
fuzz 43.85% <37.15%> (+<0.01%) ⬆️
gui-tests 58.25% <83.60%> (+0.11%) ⬆️
performance-and-unit-tests 81.03% <98.36%> (-0.01%) ⬇️
test 45.43% <81.42%> (+0.16%) ⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

Files with missing lines Coverage Δ
src/ert/config/ert_config.py 95.95% <ø> (ø)
src/ert/config/ert_script.py 88.65% <100.00%> (+1.35%) ⬆️
src/ert/config/external_ert_script.py 100.00% <100.00%> (ø)
src/ert/config/workflow.py 98.52% <100.00%> (+0.19%) ⬆️
src/ert/run_models/run_model.py 92.50% <ø> (ø)
src/ert/workflow_runner.py 94.91% <100.00%> (+2.85%) ⬆️
src/ert/config/_capture_output.py 96.05% <96.05%> (ø)

... and 1 file with indirect coverage changes

Comment thread src/ert/config/ert_script.py Outdated
@contextlib.contextmanager
def capture(self) -> Iterator[io.StringIO]:
"""Record what the calling thread writes for the duration of the block."""
buffer = io.StringIO()

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

shouldn't all of this be in the try block rather than only the yield?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

not sure i understand. The append should happen before, such that the remove in finally has something to remove. Remove should be in finally so that we know it happens. Follows pattern from contextmanager docs

Image

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I meant more like if this fails buffers = self._buffers, but I guess then we don't want to remove it from the list.
So it might be good 👍

Comment thread src/ert/config/ert_script.py Outdated
Comment thread src/ert/config/ert_script.py Outdated
Comment thread src/ert/config/ert_script.py Outdated
Comment thread src/ert/config/ert_script.py Outdated
Comment thread src/ert/config/ert_script.py Outdated
@codspeed-hq

codspeed-hq Bot commented Aug 27, 2026

Copy link
Copy Markdown

Merging this PR will not alter performance

✅ 36 untouched benchmarks


Comparing log-workflow-output (33034fb) with main (112f2c8)

Open in CodSpeed

Comment thread src/ert/config/workflow.py
Comment thread src/ert/workflow_runner.py Outdated
Comment thread docs/ert/reference/workflows/complete_workflows.rst Outdated
Comment thread src/ert/workflow_runner.py Outdated
Comment thread src/ert/workflow_runner.py Outdated
Comment thread src/ert/workflow_runner.py Outdated
Comment thread src/ert/workflow_runner.py Outdated
Comment thread src/ert/config/ert_script.py Outdated
Comment thread src/ert/config/ert_script.py Outdated
Comment thread src/ert/config/ert_script.py Outdated
Comment thread src/ert/config/ert_script.py Outdated
Comment thread src/ert/config/ert_script.py Outdated
Comment thread tests/ert/unit_tests/cli/test_cli_workflow.py Outdated
Comment thread tests/ert/unit_tests/config/test_ert_config.py Outdated
Comment thread src/ert/config/_capture_output.py Outdated
Comment thread src/ert/workflow_runner.py Outdated
CANCELLED = "cancelled"


def _job_description(

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This can't be a WorkflowJobResult member / function?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i think putting it on result is wrong, since it is used before we actually run the runner.

Image

Maybe we can put it on the runner? agree that its weird to be free

Comment thread tests/ert/unit_tests/config/test_ert_config.py Outdated
Comment thread tests/ert/unit_tests/workflow_runner/test_ert_script.py Outdated
Comment thread tests/ert/unit_tests/workflow_runner/test_ert_script.py Outdated
Comment thread tests/ert/unit_tests/workflow_runner/test_ert_script.py Outdated

@xjules xjules left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It looks already very good!
Had only a smaller comments.
Also, there are way to many articles in the test names: remove the, a and an

@erlenlh
erlenlh force-pushed the log-workflow-output branch 2 times, most recently from cebcb52 to 5682c06 Compare September 3, 2026 07:37
erlenlh and others added 10 commits September 3, 2026 09:43
Internal python workflow jobs wrote straight to sys.stdout/sys.stderr,
so their output was visible in the terminal but not available to ERT
itself. External jobs captured their subprocess output but did not pass
stdout on to the terminal.

Replace sys.stdout/sys.stderr with a proxy while a job runs, recording
what the calling thread writes while still forwarding it to the real
stream. Capture is per-thread, so concurrently running jobs do not pick
up each other's output.

Also stop reporting a failing external job with an ERT stack trace: the
new ExternalScriptError carries the exit code, since the traceback would
only show ERT internals.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
WorkflowJobRunner.run() set the running flag before validating its
arguments but only cleared it on the success path, so a job rejected for
too few or too many arguments kept reporting that it was still running.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
workflowReport() is keyed by job name, so a workflow running the same job
more than once kept only the output of the last invocation.

Add WorkflowJobResult, recording name, index, arguments, output, status
and timestamp per invocation, and expose the ordered list through
workflowJobResults(). workflowReport() is left as it is, since the run
workflow tool and the CLI still use it.

Jobs skipped because the workflow was cancelled are recorded too, so a
cancelled workflow can be told apart from one that never ran. A job that
stops the workflow is now recorded before the error is raised, so its
output is not lost.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Workflow carried no name of its own, so anything reporting on a workflow
had to fall back to the source file path. LOAD_WORKFLOW lets a workflow
be given a name, and that is the name users recognise.

Store the name on Workflow, defaulting to the file name when none is
given, so it can be reported alongside the jobs that were run.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Workflow job output only reached the terminal ERT was started from, so
it was lost once that terminal was gone, and a job run outside a terminal
left no record at all.

Write one entry per job invocation to the ERT log, naming the hook, the
workflow and the job, and quoting the arguments, stdout and stderr. This
covers hooked workflows, 'ert workflow' and the GUI Run workflow tool,
since all three go through WorkflowRunner.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Replace the failed/cancelled boolean pair on WorkflowJobResult with a
single WorkflowJobStatus enum. The two booleans could express states
that do not exist, and a job interrupted mid-run was reported as failed
because only the pre-start cancellation path set cancelled=True. Such a
job is now reported as cancelled.

Also rename workflowJobResults to workflow_job_results and fix the
heading underline length in the workflow documentation.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
_CaptureProxy overrode six members that io.IOBase already provides
identically. encoding, errors and newlines are kept because TextIOBase
defines them as descriptors returning None, so __getattr__ never sees
them, and writable is kept because IOBase defaults it to False.

The starting and result log lines both began with "Workflow job" but
meant different things. They now share one description and always state
the hook, using hook=None for runs outside a hook.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
The stream proxy and its context manager are self-contained and have
nothing to do with ErtScript beyond the single call that uses them, so
they crowded out the module they lived in.

The new module opens by stating why contextlib.redirect_stdout is not
used, since that is the first thing a reader is likely to wonder.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
The log line format is a concern of the runner, not of the result it
records: WorkflowJobResult is also persisted, and the starting line has
to be written before any result exists. Move the formatting onto
WorkflowRunner so both lines are built in one place and the dataclass
stays pure data.

Also drop articles from the test names added here and describe
LOAD_WORKFLOW's second argument as a name, matching the documentation.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
@erlenlh
erlenlh force-pushed the log-workflow-output branch from 5682c06 to 33034fb Compare September 3, 2026 08:03
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Log output from workflows

4 participants