Skip to content

Store workflow output - #14062

Open
erlenlh wants to merge 22 commits into
mainfrom
store-workflow-output
Open

Store workflow output#14062
erlenlh wants to merge 22 commits into
mainfrom
store-workflow-output

Conversation

@erlenlh

@erlenlh erlenlh commented Jul 31, 2026

Copy link
Copy Markdown
Contributor

Issue
Resolves #13320

Approach
Create new events for workflows, capture output to create events and write to log and storage seperately. Events follow the DataEvent pattern and will be consumed to frontend in a later PR.
Writes logs to Ert Logs for all workflowruns (hooked, CLI and through tools) and writes events to storage for hooked workflows.

Creates a CaptureProxy for thread-aware capture, write is recorded only if writing thread has an active capture flagged. Also needed for internal job print capture.

(Screenshot of new behavior in GUI if applicable)

  • 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')

@codecov-commenter

codecov-commenter commented Jul 31, 2026

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 95.89552% with 11 lines in your changes missing coverage. Please review.
✅ Project coverage is 91.94%. Comparing base (31248f9) to head (fa44ed8).
⚠️ Report is 38 commits behind head on main.
✅ All tests successful. No failed tests found.

Files with missing lines Patch % Lines
src/ert/config/ert_script.py 90.09% 11 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##             main   #14062      +/-   ##
==========================================
+ Coverage   91.85%   91.94%   +0.09%     
==========================================
  Files         484      482       -2     
  Lines       33581    33721     +140     
==========================================
+ Hits        30847    31006     +159     
+ Misses       2734     2715      -19     
Flag Coverage Δ
cli-tests 36.55% <86.19%> (+0.37%) ⬆️
fuzz 44.25% <41.41%> (+0.16%) ⬆️
gui-tests 58.76% <82.46%> (+0.37%) ⬆️
performance-and-unit-tests 80.89% <95.89%> (+0.43%) ⬆️
test 46.29% <80.22%> (-0.04%) ⬇️

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 96.00% <ø> (ø)
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/event.py 99.00% <100.00%> (+0.18%) ⬆️
src/ert/run_models/run_model.py 93.39% <100.00%> (+0.89%) ⬆️
src/ert/storage/local_experiment.py 96.42% <100.00%> (-1.63%) ⬇️
src/ert/workflow_runner.py 95.00% <100.00%> (+2.93%) ⬆️
src/ert/config/ert_script.py 88.46% <90.09%> (+1.15%) ⬆️

... and 33 files with indirect coverage changes

Copilot AI 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.

Pull request overview

This PR adds structured capture and persistence of workflow-job output (stdout/stderr) so that workflows hooked into experiment runs can be logged to <UPDATE_LOG_PATH>/<run_id>/workflows.log and appended to the experiment’s storage directory workflows.log. It introduces a dedicated status event for workflow output, and wires both CLI and GUI monitors to write these logs.

Changes:

  • Capture stdout/stderr for internal and external workflow jobs (including failure cases) and surface per-invocation results.
  • Introduce RunModelWorkflowLogEvent with a stable log-entry format, write it to update-log output paths, and append it to experiment storage.
  • Add unit/UI tests and docs describing the new workflow logging behavior.

Reviewed changes

Copilot reviewed 17 out of 17 changed files in this pull request and generated 3 comments.

Show a summary per file
File Description
src/ert/config/ert_script.py Adds thread-aware stdout/stderr capture proxy, plus ExternalScriptError handling to avoid ERT-internal stack traces for external job exit failures.
src/ert/config/external_ert_script.py Writes subprocess stdout/stderr to current streams (so ErtScript capture can record it) and raises ExternalScriptError with an exit-code message.
src/ert/workflow_runner.py Adds WorkflowJobResult and WorkflowRunner.jobResults() to preserve per-invocation output (including repeated job runs).
src/ert/run_models/event.py Introduces RunModelWorkflowLogEvent with as_log_entry() and write_as_log() for update-log persistence.
src/ert/run_models/run_model.py Emits workflow log events per job, buffers log entries until an experiment exists, and appends them to experiment storage.
src/ert/storage/local_experiment.py Adds workflow_log_path and append_workflow_log() to persist workflow log entries alongside the experiment.
src/ert/cli/monitor.py Writes workflow log events to <UPDATE_LOG_PATH>/<run_id>/workflows.log during CLI runs.
src/ert/gui/experiments/run_dialog.py Writes workflow log events to the GUI output path.
tests/ert/unit_tests/workflow_runner/test_workflow_runner.py Adds coverage for external-job stdout capture, exit-code error reporting, and per-invocation job results.
tests/ert/unit_tests/workflow_runner/test_ert_script.py Adds coverage for stdout/stderr capture, failure behavior, and concurrent/threaded capture isolation.
tests/ert/unit_tests/run_models/test_workflow_log_event.py New tests for RunModelWorkflowLogEvent log formatting and file append semantics.
tests/ert/unit_tests/run_models/test_status_events_serialization.py Extends status-event serialization coverage to include RunModelWorkflowLogEvent.
tests/ert/unit_tests/run_models/test_base_run_model.py Adds tests asserting workflow log event emission and storage persistence behavior across hooks/iterations.
tests/ert/unit_tests/gui/experiments/test_run_dialog.py Adds GUI test to verify workflow log events are written to the output path.
tests/ert/ui_tests/cli/test_cli.py Adds CLI UI test ensuring workflow output is written into the update log path.
docs/ert/reference/workflows/complete_workflows.rst Documents that hooked workflow output is also written to update-log and experiment storage logs.
docs/ert/reference/configuration/keywords.rst Documents the workflow log location/format under UPDATE_LOG_PATH, including storage-copy behavior and hook scope.
Suppressed comments (1)

tests/ert/unit_tests/workflow_runner/test_ert_script.py:183

  • Thread exceptions can be missed, and the join loop doesn’t assert that worker threads actually finished. Add an is_alive() assertion after each join so this test fails deterministically instead of leaking threads on failure paths.
    for thread in threads:
        thread.start()
    for thread in threads:
        thread.join(timeout=10)

Comment thread tests/ert/unit_tests/workflow_runner/test_workflow_runner.py Outdated
Comment thread tests/ert/unit_tests/workflow_runner/test_ert_script.py Outdated
Comment thread docs/ert/reference/workflows/complete_workflows.rst Outdated
@erlenlh
erlenlh force-pushed the store-workflow-output branch from 69e54f9 to 53b84d8 Compare August 3, 2026 14:00
Comment thread docs/ert/reference/workflows/complete_workflows.rst Outdated
erlenlh and others added 16 commits August 5, 2026 09:35
Internal python workflow jobs never captured stdout, and only recorded
stderr when they failed, so their output was lost. Tee the streams while
the script runs so the output is both recorded and still shown in the
terminal.

External jobs now write the output of the subprocess to the current
stdout and stderr instead of assigning it directly, so that both kinds of
job are captured by the same mechanism. As a consequence a stack trace
from a failing job is appended to, rather than replacing, whatever the
job printed before it failed.

This is a prerequisite for storing workflow output in a log file.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
The workflow report is keyed by job name, so a workflow that runs the
same job more than once only keeps the output of the last invocation.
Add an ordered list of results alongside it, which is needed to report
the output of all invocations.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Introduce a status event carrying the stdout and stderr of a single
workflow job invocation, which appends it to a workflows.log file under
the update log path.

The event deliberately does not inherit RunModelEvent, since the
PRE_EXPERIMENT hook runs before any ensemble exists and therefore has
neither an iteration nor an ensemble id.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
The stdout and stderr of workflows hooked into an experiment was only
visible in the terminal, and lost as soon as it scrolled away. Send the
output of every workflow job as a status event and append it to
<UPDATE_LOG_PATH>/<run_id>/workflows.log, the same way update reports are
written by the CLI monitor and the run dialog.

The events are sent even when a job with STOP_ON_FAIL aborts the
workflow, so that the output explaining the failure is kept.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

# Conflicts:
#	src/ert/run_models/run_model.py
When an external workflow job exits with a non-zero code, the stderr
recorded for the job ended with a python stack trace through the ert
internals that started the job. It says nothing about what went wrong in
the job itself, and is now noise in the workflow log. Report only the
executable and its exit code instead.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
The workflow log was only written by the CLI monitor and the GUI run
dialog, so it was lost whenever no consumer drained the status queue,
and it was not kept together with the experiment it described.

Write the same log entries from RunModel into the storage directory of
the experiment. Entries from hooks that run before the experiment exists,
such as PRE_EXPERIMENT, are buffered and flushed once an experiment is
available. The status event is kept so the output can be streamed live to
a frontend, and the update log copy is kept for backwards compatibility.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Workflow jobs run in a background thread, but the output was captured by
replacing the process wide sys.stdout and sys.stderr. Output written by
any other thread ended up in the log of whichever job happened to be
running, and two jobs running at the same time captured each other.

Route writes through a proxy that records them only for threads that are
capturing, and that delegates the rest of the stream interface to the
stream it replaced. Jobs asking for a file descriptor, an encoding or a
binary buffer now see what they would have seen without capturing, where
before they were met with an UnsupportedOperation.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Output from hooks that run before the experiment exists in storage was
flushed from inside the loop over the workflows of the current hook. A
configuration whose only hooked workflow is a PRE_EXPERIMENT one never
entered that loop again, so its output was buffered and then dropped,
contrary to what the documentation promises.

Flush whenever run_workflows is given an experiment, whether or not the
hook has any workflows of its own.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
LOAD_WORKFLOW takes an optional name to refer to the workflow by, but
only the file it was read from was kept. The workflow log therefore named
a workflow after its file, which is not what the user sees anywhere else.

Keep the given name on the workflow, falling back to the file name when
LOAD_WORKFLOW was used without one.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
A job runner reported that it was still running for the rest of its
lifetime whenever the job it started raised, since the flag was only
cleared on the path where the job returned. Rejected arguments left the
runner in the same state.

Clear the flag in a finally block covering the whole run.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
The threads were joined with a timeout but the result was ignored, so a
thread that never finished left the test asserting on half written output
and reporting whatever it found. A stuck job is worse than a failed one
here, since its capture block never exits and sys.stdout stays replaced
for the rest of the session.

Assert that each thread terminated, naming the consequence in the message.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Keep only what the signature does not already say, namely why the method
can return without writing anything.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Drop a formatting test that only re-asserted what the two tests
around it already covered, and add tests for three paths that were
untested: that a new experiment run discards output left pending by
the previous one, that appending to an experiment log accumulates and
is refused by read-only storage, and that output still reaches storage
when a workflow aborts on failure or the user cancels the run.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Workflow output was written both to the update log path by the CLI
and GUI and to the experiment in storage by the run model, leaving
two copies of the same content to keep in sync. The storage copy is
the durable one: it lives with the data of the experiment it belongs
to, no matter which frontend started the run.

Drop the update log copy and the write_as_log helper behind it. The
event itself stays, since it remains the only live channel to the
frontend.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
The workflow log was described under UPDATE_LOG_PATH, which no longer
holds it. Move the description to the workflow reference, where the
hooks that produce it are documented.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
@erlenlh
erlenlh force-pushed the store-workflow-output branch from 11a454c to 74d8bfe Compare August 5, 2026 07:42
@codspeed-hq

codspeed-hq Bot commented Aug 5, 2026

Copy link
Copy Markdown

Merging this PR will not alter performance

✅ 36 untouched benchmarks


Comparing store-workflow-output (fa44ed8) with main (0dc49c7)

Open in CodSpeed

A cooperatively-cancelled internal job returns normally, so hasFailed()
stays False and the job was indistinguishable from one that ran to
completion. WorkflowJobResult and RunModelWorkflowLogEvent now carry a
'cancelled' flag alongside 'failed', and the persisted log entry status
reflects it.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
@erlenlh
erlenlh force-pushed the store-workflow-output branch from 03e0e55 to 598ec95 Compare August 10, 2026 07:49
erlenlh and others added 4 commits August 10, 2026 14:29
When several workflows are hooked to the same runtime (e.g. multiple
HOOK_WORKFLOW ... POST_EXPERIMENT lines) and the experiment is
cancelled while an earlier one is still running, run_workflows()
raised UserCancelled immediately, breaking out of the loop before any
later hooked workflow was even instantiated. Those workflows produced
zero events and vanished from the workflow log/GUI instead of showing
up as cancelled.

Skip workflows that haven't started once cancellation is detected and
emit a cancelled event for each of their jobs, then defer the
UserCancelled raise until after the loop so all hooked workflows are
still reported.
The bespoke workflows.log file only covered hooked workflows and
duplicated information the logging system already handles well.
Workflow job output (stdout/stderr, arguments, status) is now
formatted into the message of a normal log record emitted through
ert.workflow_runner, so it appears in ert-*.log regardless of
whether the workflow was hooked to an experiment, run from the CLI,
or run from the Tools menu.

Job results are logged once, before stop_on_fail aborts the
workflow, so the output of the job that stopped the workflow is no
longer silently dropped.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Replace workflow_log_path/append_workflow_log with
workflow_events_path/append_workflow_events, which appends one
pre-serialized JSON line per event to workflow_events.jsonl. Storage
stays free of any dependency on ert.run_models: it only ever
receives strings to append.

This file is not meant to be read by users directly (the ERT log
now covers that); it exists so a later GUI can repopulate workflow
output for older experiments.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
RunModel now serializes each RunModelWorkflowLogEvent with
model_dump_json() and appends the resulting lines via
append_workflow_events(), instead of writing pre-formatted log
text. This only applies to workflows hooked to an experiment; CLI
and Tools-menu workflows rely solely on the ERT logger.

Document the new behaviour: workflow output goes to the ERT log for
all three entry points, and workflow_events.jsonl is a GUI-backing
file, not meant to be read directly.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
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.

Store output from workflows

4 participants