diff --git a/cylc/flow/task_events_mgr.py b/cylc/flow/task_events_mgr.py index 121b4ae4e5..821fc09c37 100644 --- a/cylc/flow/task_events_mgr.py +++ b/cylc/flow/task_events_mgr.py @@ -1324,6 +1324,7 @@ def _process_message_failed( "run_status": 1, "time_run_exit": event_time, }) + LOG.error(f'[{itask}] {full_message or self.EVENT_FAILED}') if ( forced or TimerFlags.EXECUTION_RETRY not in itask.try_timers @@ -1338,9 +1339,6 @@ def _process_message_failed( self.data_store_mgr.delta_task_output( itask, TASK_OUTPUT_FAILED) self.data_store_mgr.delta_task_state(itask) - LOG.error( - f'[{itask}] {full_message or self.EVENT_FAILED} - ' - ) else: # There is an execution retry lined up. timer = itask.try_timers[TimerFlags.EXECUTION_RETRY] @@ -1428,6 +1426,7 @@ def _process_message_submit_failed( "submit_status": 1, }) itask.summary['submit_method_id'] = None + LOG.error(f"[{itask}] {self.EVENT_SUBMIT_FAILED}") if ( forced or TimerFlags.SUBMISSION_RETRY not in itask.try_timers @@ -1446,7 +1445,6 @@ def _process_message_submit_failed( self.data_store_mgr.delta_task_output( itask, TASK_OUTPUT_SUBMIT_FAILED) self.data_store_mgr.delta_task_state(itask) - LOG.error(f"[{itask}] {self.EVENT_SUBMIT_FAILED}") else: # There is a submission retry lined up. timer = itask.try_timers[TimerFlags.SUBMISSION_RETRY] diff --git a/tests/functional/cylc-trigger/02-filter-failed/flow.cylc b/tests/functional/cylc-trigger/02-filter-failed/flow.cylc index 342f144998..3da59a7d86 100644 --- a/tests/functional/cylc-trigger/02-filter-failed/flow.cylc +++ b/tests/functional/cylc-trigger/02-filter-failed/flow.cylc @@ -18,9 +18,9 @@ [[fixer]] script = """ cylc__job__wait_cylc_message_started - cylc__job__poll_grep_workflow_log -E '\[1/fixable1/01:failed\] failed/ERR' - cylc__job__poll_grep_workflow_log -E '\[1/fixable2/01:failed\] failed/ERR' - cylc__job__poll_grep_workflow_log -E '\[1/fixable3/01:failed\] failed/ERR' + cylc__job__poll_grep_workflow_log -E '\[1/fixable1/01:running\] failed/ERR' + cylc__job__poll_grep_workflow_log -E '\[1/fixable2/01:running\] failed/ERR' + cylc__job__poll_grep_workflow_log -E '\[1/fixable3/01:running\] failed/ERR' cylc trigger "${CYLC_WORKFLOW_ID}//1/fixable*" """ [[Z]] diff --git a/tests/integration/test_task_events_mgr.py b/tests/integration/test_task_events_mgr.py index a8da192b86..0055797113 100644 --- a/tests/integration/test_task_events_mgr.py +++ b/tests/integration/test_task_events_mgr.py @@ -174,7 +174,7 @@ async def test__always_insert_task_job( } -async def test__process_message_failed_with_retry(one, start): +async def test__process_message_failed_with_retry(one, start, log_filter): """Log job failure, even if a retry is scheduled. See: https://github.com/cylc/cylc-flow/pull/6169 @@ -199,9 +199,8 @@ async def test__process_message_failed_with_retry(one, start): one.task_events_mgr._process_message_submit_failed( fail_once, None, 2, False) - last_record = LOG.records[-1] - assert last_record.levelno == logging.ERROR - assert 'submission failed' in last_record.message + failed_record = log_filter(LOG, level=logging.ERROR)[-1] + assert 'submission failed' in failed_record[2] # Process failed message with and without retries: one.task_events_mgr._process_message_failed( @@ -212,6 +211,5 @@ async def test__process_message_failed_with_retry(one, start): one.task_events_mgr._process_message_failed( fail_once, None, 'failed', False, 'failed/OOK') - last_record = LOG.records[-1] - assert last_record.levelno == logging.ERROR - assert 'failed/OOK' in last_record.message + failed_record = log_filter(LOG, level=logging.ERROR)[-1] + assert 'failed/OOK' in failed_record[2]