Skip to content

Commit 598ec95

Browse files
erlenlhCopilot
andcommitted
Record when a workflow job was cancelled, not just failed
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>
1 parent 74d8bfe commit 598ec95

6 files changed

Lines changed: 142 additions & 37 deletions

File tree

src/ert/run_models/event.py

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -106,11 +106,17 @@ class RunModelWorkflowLogEvent(BaseModel, extra="forbid"):
106106
stdout: str
107107
stderr: str
108108
failed: bool
109+
cancelled: bool = False
109110
timestamp: datetime
110111
iteration: int | None = None
111112

112113
def as_log_entry(self) -> str:
113-
status = "failed" if self.failed else "success"
114+
if self.cancelled:
115+
status = "cancelled"
116+
elif self.failed:
117+
status = "failed"
118+
else:
119+
status = "success"
114120
header = (
115121
f"=== {self.timestamp.isoformat(timespec='seconds')} {self.hook} "
116122
f"workflow={self.workflow_name} job={self.job_name}#{self.job_index} "

src/ert/run_models/run_model.py

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -887,6 +887,7 @@ def _send_workflow_log_events(
887887
stdout=result.stdout,
888888
stderr=result.stderr,
889889
failed=result.failed,
890+
cancelled=result.cancelled,
890891
timestamp=result.timestamp,
891892
iteration=iteration,
892893
)

src/ert/workflow_runner.py

Lines changed: 61 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,7 @@ class WorkflowJobResult:
2929
stdout: str
3030
stderr: str
3131
failed: bool
32+
cancelled: bool = False
3233
timestamp: datetime.datetime = field(
3334
default_factory=lambda: datetime.datetime.now(tz=datetime.UTC)
3435
)
@@ -166,51 +167,75 @@ def run_blocking(self) -> None:
166167
self.__running = True
167168

168169
for index, (job, args) in enumerate(self.__workflow):
169-
jobrunner = WorkflowJobRunner(job)
170-
self.__current_job = jobrunner
171-
if not self.__cancelled:
172-
logger.info(f"Workflow job {jobrunner.name} starting")
173-
jobrunner.run(args, fixtures=self.fixtures)
174-
self.__status[jobrunner.name] = {
175-
"stdout": jobrunner.stdoutdata(),
176-
"stderr": jobrunner.stderrdata(),
177-
"completed": not jobrunner.hasFailed(),
178-
}
170+
if self.__cancelled:
171+
# The workflow was already cancelled before this job got a
172+
# chance to start - record it as cancelled rather than
173+
# silently dropping it.
179174
self.__job_results.append(
180175
WorkflowJobResult(
181-
name=jobrunner.name,
176+
name=job.name,
182177
index=index,
183178
arguments=[str(arg) for arg in args],
184-
stdout=jobrunner.stdoutdata(),
185-
stderr=jobrunner.stderrdata(),
186-
failed=jobrunner.hasFailed(),
179+
stdout="",
180+
stderr="",
181+
failed=False,
182+
cancelled=True,
187183
)
188184
)
185+
continue
186+
187+
jobrunner = WorkflowJobRunner(job)
188+
self.__current_job = jobrunner
189+
logger.info(f"Workflow job {jobrunner.name} starting")
190+
jobrunner.run(args, fixtures=self.fixtures)
191+
job_was_cancelled = self.__cancelled
192+
# A job that was interrupted by a cancellation request did not
193+
# complete, so it is reported as failed rather than succeeded -
194+
# cooperatively cancelled internal jobs otherwise return
195+
# normally and hasFailed() would stay False.
196+
failed = jobrunner.hasFailed() or job_was_cancelled
197+
self.__status[jobrunner.name] = {
198+
"stdout": jobrunner.stdoutdata(),
199+
"stderr": jobrunner.stderrdata(),
200+
"completed": not failed,
201+
}
202+
self.__job_results.append(
203+
WorkflowJobResult(
204+
name=jobrunner.name,
205+
index=index,
206+
arguments=[str(arg) for arg in args],
207+
stdout=jobrunner.stdoutdata(),
208+
stderr=jobrunner.stderrdata(),
209+
failed=failed,
210+
)
211+
)
189212

190-
info = {
191-
"class": "WORKFLOW_JOB",
192-
"job_name": jobrunner.name,
193-
"arguments": " ".join(args),
194-
"stdout": jobrunner.stdoutdata(),
195-
"stderr": jobrunner.stderrdata(),
196-
"execution_type": jobrunner.execution_type,
197-
}
198-
199-
if jobrunner.hasFailed():
200-
if jobrunner.stop_on_fail:
201-
self.__running = False
202-
raise RuntimeError(
203-
f"Workflow job {info['job_name']}"
204-
f" failed with error: {info['stderr']}"
205-
)
206-
207-
logger.error(f"Workflow job {jobrunner.name} failed", extra=info)
208-
else:
209-
logger.info(
210-
f"Workflow job {jobrunner.name} completed successfully",
211-
extra=info,
213+
info = {
214+
"class": "WORKFLOW_JOB",
215+
"job_name": jobrunner.name,
216+
"arguments": " ".join(args),
217+
"stdout": jobrunner.stdoutdata(),
218+
"stderr": jobrunner.stderrdata(),
219+
"execution_type": jobrunner.execution_type,
220+
}
221+
222+
if job_was_cancelled:
223+
logger.info(f"Workflow job {jobrunner.name} was cancelled", extra=info)
224+
elif jobrunner.hasFailed():
225+
if jobrunner.stop_on_fail:
226+
self.__running = False
227+
raise RuntimeError(
228+
f"Workflow job {info['job_name']}"
229+
f" failed with error: {info['stderr']}"
212230
)
213231

232+
logger.error(f"Workflow job {jobrunner.name} failed", extra=info)
233+
else:
234+
logger.info(
235+
f"Workflow job {jobrunner.name} completed successfully",
236+
extra=info,
237+
)
238+
214239
self.__current_job = None
215240
self.__running = False
216241
self.__workflow_result = True

tests/ert/unit_tests/run_models/test_base_run_model.py

Lines changed: 54 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -43,6 +43,7 @@
4343
UserCancelled,
4444
)
4545
from ert.warnings import PostExperimentWarning
46+
from ert.workflow_runner import WorkflowJobResult
4647

4748

4849
@pytest.fixture(autouse=True)
@@ -959,6 +960,59 @@ def test_that_a_workflow_log_event_is_sent_when_stop_on_fail_aborts_the_workflow
959960
assert event.stdout == "printed before failing\n"
960961

961962

963+
def test_that_a_cancelled_job_and_its_unstarted_siblings_carry_the_workflow_name(
964+
use_tmpdir,
965+
):
966+
"""Regression test: a job interrupted by cancellation is reported as
967+
failed (not merely cancelled), the jobs after it that never got a
968+
chance to start are reported as cancelled, and both kinds of result
969+
still carry the originating workflow's name once turned into events.
970+
"""
971+
status_queue = SimpleQueue()
972+
brm = create_run_model(
973+
hooked_workflows={},
974+
status_queue=status_queue,
975+
)
976+
977+
workflow_runner = MagicMock()
978+
workflow_runner.workflowJobResults.return_value = [
979+
WorkflowJobResult(
980+
name="INTERRUPTED",
981+
index=0,
982+
arguments=[],
983+
stdout="partial output",
984+
stderr="",
985+
failed=True,
986+
cancelled=False,
987+
),
988+
WorkflowJobResult(
989+
name="NEVER_STARTED",
990+
index=1,
991+
arguments=[],
992+
stdout="",
993+
stderr="",
994+
failed=False,
995+
cancelled=True,
996+
),
997+
]
998+
999+
brm._send_workflow_log_events(
1000+
workflow_runner=workflow_runner,
1001+
hook=HookRuntime.PRE_SIMULATION,
1002+
workflow_name="my_workflow",
1003+
iteration=0,
1004+
)
1005+
1006+
interrupted_event, never_started_event = _drain(status_queue)
1007+
assert interrupted_event.workflow_name == "my_workflow"
1008+
assert interrupted_event.failed
1009+
assert not interrupted_event.cancelled
1010+
1011+
assert never_started_event.workflow_name == "my_workflow"
1012+
assert not never_started_event.failed
1013+
assert never_started_event.cancelled
1014+
1015+
9621016
def test_that_workflow_log_events_from_an_update_hook_carry_the_iteration(
9631017
tmp_path, use_tmpdir
9641018
):

tests/ert/unit_tests/run_models/test_workflow_log_event.py

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,12 @@ def test_that_workflow_log_entry_header_states_hook_workflow_job_and_status():
5353
)
5454

5555

56+
def test_that_a_cancelled_job_is_reported_as_cancelled_even_if_not_failed():
57+
entry = _event(cancelled=True, failed=False).as_log_entry()
58+
59+
assert "status=cancelled" in entry.splitlines()[0]
60+
61+
5662
def test_that_workflow_log_entries_are_separated_by_a_blank_line():
5763
first = _event(job_name="FIRST", stdout="first\n").as_log_entry()
5864
second = _event(job_name="SECOND", stdout="second\n").as_log_entry()

tests/ert/unit_tests/workflow_runner/test_workflow_runner.py

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -228,6 +228,7 @@ def test_that_job_results_contain_one_entry_per_job_invocation():
228228
]
229229
assert [result.stdout for result in results] == ["Hello World\n", "Hello World\n"]
230230
assert not any(result.failed for result in results)
231+
assert not any(result.cancelled for result in results)
231232

232233

233234
@pytest.mark.slow
@@ -267,6 +268,18 @@ def test_workflow_thread_cancel_ert_script():
267268
assert not Path("wait_cancelled_2").exists()
268269
assert not Path("wait_finished_2").exists()
269270

271+
results = {result.index: result for result in workflow_runner.workflowJobResults()}
272+
assert results[0].cancelled is False
273+
assert results[0].failed is False
274+
# The job that was interrupted by cancellation did not complete, so it
275+
# is reported as failed rather than as a separate "cancelled" status.
276+
assert results[1].cancelled is False
277+
assert results[1].failed is True
278+
# The remaining job never got a chance to start, so it is reported as
279+
# cancelled rather than silently omitted.
280+
assert results[2].cancelled is True
281+
assert results[2].failed is False
282+
270283

271284
@pytest.mark.slow
272285
@pytest.mark.usefixtures("use_tmpdir")

0 commit comments

Comments
 (0)