Cylc-flow: Cylc Validate check custom task outputs

[datamel]

Cylc message triggers can not have a colon in them unless it is a valid severity level eg. warning.
We should check to ensure that the trigger is valid.

[oliver-sanders]

Can add to the cylc/flow/unicode_rules.py file.

[oliver-sanders]

See also #2979

[MetRonnie]

Steps to reproduce problem:

1. flow.cylc:

```
[scheduling]
    cycling mode = integer
    [[graph]]
        R1 = (joyce:foo & joyce:bar) => wilder

[runtime]
    [[joyce]]
        script = """
            sleep 2
            cylc message -- "$CYLC_SUITE_NAME" "$CYLC_TASK_JOB" \
                'Time machine location: Bradbury Swimming Pool'
            sleep 2
            cylc message -- "$CYLC_SUITE_NAME" "$CYLC_TASK_JOB" \
                'Chronon Field Regulator'
        """
        [[[outputs]]]
            foo = Time machine location: Bradbury Swimming Pool
            bar = Chronon Field Regulator
    [[wilder]]
        script = sleep 2
```

1. $ cylc run

   This results in the following job.out:

   T17:23:47 INFO - started
   T17:23:50 Time machine location - Bradbury Swimming Pool
   T17:23:53 INFO - Chronon Field Regulator
   

   i.e. the bit before the colon is treated as the severity level. The suite log contains:

   T17:23:50 INFO - [joyce.1] status=running: (received)Bradbury Swimming Pool at 2020-08-24T17:23:50+01:00  for job(01) flow(G)
   T17:23:54 INFO - [joyce.1] status=running: (received)Chronon Field Regulator at 2020-08-24T17:23:53+01:00  for job(01) flow(G)
   T17:23:56 INFO - [joyce.1] -Succeeded with outputs not completed:
       Time machine location: Bradbury Swimming Pool
   

[hjoliver]

T17:23:50 Time machine location -

Fair play, that is the best severity level I've ever seen :rofl:

[MetRonnie]

I've just seen in the docs:

“CUSTOM” severity messages are printed to job.out, logged by the suite server program, and can be used to trigger custom event handlers:

cylc message -- "${CYLC_SUITE_NAME}" "${CYLC_TASK_JOB}" \
  "CUSTOM:data available for ${CYLC_TASK_CYCLE_POINT}"

These can be used to signal special events that are neither routine information nor an error condition, such as production of a particular data file (a “data availability” event).

which is at odds with this issue.

Should I add the literal CUSTOM to the allowed unicode rules?

[MetRonnie]

Actually, that's for task messaging alone (cylc message ...) without any mention of the [runtime][X][outputs] _triggers_.

[oliver-sanders]

@hjoliver what the heck is this CUSTOM severity?

[hjoliver]

Sorry, I should have noticed that :grimacing:

[hjoliver]

(Trying to recall what the heck it is!)

[hjoliver]

2410 - implemented for, and heavily used by, BOM.

It is a somewhat crude way of triggering event handlers off of "custom" task messages (which are not necessarily registered task outputs used for triggering other tasks). The use case was: task sends a "data availability message" back to the scheduler, which passes it to an event handler for publication to a message broker (that other workflows subscribe to).

[hjoliver]

Struggling to recall now, but message priority/severity was probably the easiest way to do this, because it is additional context for the message without having to alter the message itself, that we already handle (for CRITICAL and WARNING messages etc.) and that we already use to to trigger event handlers. (But the existing levels weren't really appropriate for the aforementioned use case).

[MetRonnie]

Actually, that's for task messaging alone (cylc message ...) without any mention of the [runtime][X][outputs] _triggers_.

... therefore you can use CUSTOM: (or anything) in cylc message, but not in [runtime][X][outputs]<output>. I may have botched the PR somewhat 😬

This works:

[scheduling]
    cycling mode = integer
    [[graph]]
        R1 = joyce:foo => wilder
[runtime]
    [[joyce]]
        script = """
            sleep 2
            cylc message -- "$CYLC_SUITE_NAME" "$CYLC_TASK_JOB" \
                'Time machine location: Bradbury Swimming Pool'
        """
        [[[outputs]]]
            foo = Bradbury Swimming Pool
    [[wilder]]
        script = true

So in job.out you get:

INFO - started
Time machine location - Bradbury Swimming Pool
INFO - succeeded

But, this does not work:

[runtime]
    [[joyce]]
        script = """
            sleep 2
            cylc message -- "$CYLC_SUITE_NAME" "$CYLC_TASK_JOB" \
                'INFO: Bradbury Swimming Pool'
        """
        [[[outputs]]]
            foo = INFO: Bradbury Swimming Pool

and in the suite log you get:

WARNING - suite stalled
WARNING - Unmet prerequisites for wilder.1:
WARNING -  * joyce.1 INFO: Bradbury Swimming Pool

because it's expecting INFO: INFO: Bradbury Swimming Pool, i.e.:
```
cylc message -- "$CYLC_SUITE_NAME" "$CYLC_TASK_JOB" \
'INFO: INFO: Bradbury Swimming Pool'

[MetRonnie]

Proposal

In cylc message:

• Allow the literal CUSTOM severity level (or should it be any custom severity level (probably without any whitespace) @hjoliver ?) followed by a colon, and not allow any further colons

In [runtime][<task>][outputs]<output>:

• Not allow any colons

[hjoliver]

(Note that this feature can be used just for event handling, without associated task outputs for task triggering - as in the use case I mentioned above - but we should make sure it works for both at once of course).

In the current implementation:

• any <LEVEL>: string used in cylc message will be logged as a severity level
• but only literal CUSTOM: level has an associated "custom" event that can trigger an event handler

So if you want to trigger event handlers off of several different kinds of events in task, you would have to handle them all with the custom event (i.e. a single handler would have to triage all the different events and decide what to do with them).

Given that severity logging works for any LEVEL: string, not just CUSTOM: and the standard levels, maybe we should dynamically create events based on severity level in incoming messages. Not sure if that would be difficult to implement. This could be a follow-up issue though.

For the minimal fix, to answer your questions above:

• I think we should allow any custom severity level - since that already works for logging as just described, and it opens up the possibility of having associated custom events
• It seems to me that not allowing any other colons in task messages is probably OK, because these messages have entirely user-defined semantics (so users could replace a desired colon with something else and have an event handler translate accordingly). As far as Cylc is concerned they are just strings that a) get logged; b) might get passed event handlers; and c) might match a registered output used for task triggering.