Log job failure even when there are retries configured

[wxtim]

Closes #6151

Check List

• I have read CONTRIBUTING.md and added my name as a Code Contributor.
• Contains logically grouped changes (else tidy your branch by rebase).
• Does not contain off-topic changes (use other PRs for other changes).
• Applied any dependency changes to both setup.cfg (and conda-environment.yml if present).
• Tests are included (or explain why tests are not needed).
• CHANGES.md entry included if this is a change that can affect users
• Cylc-Doc pull request opened if required at cylc/cylc-doc/pull/XXXX.
• If this is a bug fix, PR should be raised against the relevant ?.?.x branch.

[oliver-sanders]

Unfortunately, I don't think it's this simple.

• I think this diff means that polled log messages for task failure will go back to being duplicated.
• This only covers failure, but submission failure also has retries so may require similar treatment.
• I think the failures before retries are exhausted will now get logged at CRITICAL level rather than INFO.

[wxtim]

I think this diff means that polled log messages for task failure will go back to being duplicated.

I think that you have a particular closed issue in mind, but I can't find it... Can you point it out to me?

This only covers failure, but submission failure also has retries so may require similar treatment.

I think that submission failure is already handled correctly - it certainly is in the simplistic case where you feed it platform=garbage you get a submission failed message at level critical:

CRITICAL - [1/bar/01:preparing] submission failed
CRITICAL - [1/bar/02:preparing] submission failed
CRITICAL - [1/bar/03:preparing] submission failed

These are logged at critical - and I think they should be?

I think the failures before retries are exhausted will now get logged at CRITICAL level rather than INFO.

This would be consistent with submit failure...

[oliver-sanders]

I think this diff means that polled log messages for task failure will go back to being duplicated.

I think that you have a particular closed issue in mind, but I can't find it... Can you point it out to me?

No, I'm not thinking of the other log message duplication issue.

The change made here bypassed logic that was used for suppressing duplicate log messages (the f'{FAIL_MESSAGE_PREFIX}ERR' bit):

8f20ab0#diff-d6de42ef75ecc801c26a6be3a9dc4885b64db89d32bce6f07e319595257b9b2eL930

However, in your more recent "fix" commit, you have put this back the way it was before:

3cedf2f#diff-d6de42ef75ecc801c26a6be3a9dc4885b64db89d32bce6f07e319595257b9b2eR930

because I'm blind

[wxtim]

This does not apply to submit failure, because submit failure will always log a critical warning through the jobs-submit command.

WARNING - platform: mulberry - Could not connect to mymachine.
    * mymachine has been added to the list of unreachable hosts
    * remote-init will retry if another host is available.
ERROR - [jobs-submit cmd] (remote init)
    [jobs-submit ret_code] 1
CRITICAL - [1/bar/02:preparing] submission failed
INFO - [1/bar/02:preparing] => waiting
WARNING - [1/bar:waiting] retrying in PT1S (after 2024-07-22T14:51:37+01:00)

[MetRonnie]

(Test failures)

[wxtim]

These test failures were caused by a slight change in the nature of the message caused by moving it: By the time the code reaches _process_message_failed some of the info required for the original error messages (the state) is not available, or has changed.

[hjoliver]

One small typo found.

[hjoliver]

@wxtim this seems to have diverged a bit from what I thought was agreed above, which was:

• log the job (or submit) failure as ERROR whether there are retries or not
• then log the retry message at WARNING level, if there are retries

Now, if there are retries we only get the retry warning. (Which I think is back to the problem we were trying to fix here, although the logging location has changed to the methods that would support the fix).

[MetRonnie]

The execution retry log message is now:

WARNING - [1/foo:waiting] failed/ERR - retrying in ...

Whereas the submission retry log message is still just:

WARNING - [1/foo:waiting] retrying in ...

I think it would make sense to update this too.

[MetRonnie]

Less fragile if this was just set in the workflow config for the test?

[wxtim]

Does it really make any difference? - the aim was to avoid fiddling with one. Can do if you insist.

[MetRonnie]

Surely creating a workflow config with these retry delays set is not any more involved than fiddling the internal retry timers?

[wxtim]

Not going to argue. Will change.

[wxtim]

Went away and had a look at it - essentially this is more unit-testy than integration test-like: If you set these timers in the config you still need to run this function here to set the retry timers. So I think that I'll leave it.

[hjoliver]

Here's a screenshot comparing two execution failures (one retry) with two submission failures (one retry):

Contrary to @MetRonnie 's suggestion (I think) you just need to get rid of the failed/ERR bit in the execution retry message. That information is already logged as the error. The warning is just about the resulting retry.

[hjoliver]

Or have "execution retrying in..." and "submission retrying in..."?

Not really necessary because both entail a full "retry" (i.e., submit the job, then execute it).

[hjoliver]

Still waiting on my suggestion above, I think. In case it got a bit lost in the log lines:

# submission retry (good)
ERROR - [1/foo/01:preparing] submission failed
INFO - [1/foo/01:preparing] => waiting
WARNING - [1/foo:waiting] retrying in PT5S (after 2025-01-09T11:08:20+13:00)

# execution retry (needs tweak)
ERROR - [1/foo/01:running] failed/ERR
INFO - [1/foo/01:running] => waiting
WARNING - [1/foo:waiting] failed/ERR - retrying in PT5S (after 2025-01-09T11:05:49+13:00)

(Pretty minor, but there's no need to double-log the failed/ERR bit).

[wxtim]

Still waiting on my suggestion #6169 (comment), I think. In case it got a bit lost in the log lines:

Done, but not pushed, because I was was also looking at Ronnie's Comments about the tests.