Make set trigger outputs in order

[wxtim]

What has changed in this branch.

Cylc set sorts outputs before emitting them.

What problem does this solve

if you run a simple workflow:

[scheduling]
    cycling mode = integer
    [[graph]]
        R1 = """
            foo:a & foo:b => bar
        """

[runtime]
    [[foo]]
        script = sleep 300
        [[[outputs]]]
            a = 'apple (poisoned)'
            b = 'banshee'
    [[bar]]

set it running then

cylc set set/basic//1/foo    # --out=required

gets the following message:

2024-03-11T13:48:42Z INFO - [1/foo/01:submitted] setting implied output: started
2024-03-11T13:48:42Z INFO - [1/foo/01:submitted] => succeeded
2024-03-11T13:48:42Z WARNING - [1/foo/01:succeeded] did not complete required outputs: ['a', 'b']
2024-03-11T13:48:42Z INFO - [1/foo/01:succeeded] completed output a
2024-03-11T13:48:42Z INFO - [1/bar:waiting(runahead)] added to active task pool
2024-03-11T13:48:42Z INFO - [1/bar:waiting(runahead)] => waiting
2024-03-11T13:48:42Z INFO - [1/foo/01:succeeded] completed output b

Confusing IMO.

[oliver-sanders]

Gets rid of the erroneous warning 👍

[oliver-sanders]

If you set multiple outputs on a task, then they will be set one by one. After each output is set, tasks may spawn, have their runahead status changed or be queued. This makes the logs a bit hard to read as log entries relating to the outputs being set are dispersed amongst log entries from other activities.

E.G, this section of log:

2024-03-11T13:57:36Z INFO - Command "set" received. ID=3003469a-d82d-4434-9d28-ff0950dc87d3
    set(flow=['all'], flow_wait=False, outputs=[], prerequisites=[], tasks=['1/foo'])
2024-03-11T13:57:36Z INFO - [1/foo:waiting(queued)] completed output a
2024-03-11T13:57:36Z INFO - [1/bar:waiting(runahead)] added to active task pool
2024-03-11T13:57:36Z INFO - [1/bar:waiting(runahead)] => waiting
2024-03-11T13:57:36Z INFO - [1/foo:waiting(queued)] completed output b
2024-03-11T13:57:36Z INFO - [1/bar:waiting] added to active task pool
2024-03-11T13:57:36Z INFO - [1/bar:waiting] => waiting(queued)
2024-03-11T13:57:36Z INFO - [1/foo:waiting(queued)] setting implied output: submitted
2024-03-11T13:57:36Z INFO - [1/foo:waiting(queued)] setting implied output: started
2024-03-11T13:57:36Z INFO - [1/foo:waiting(queued)] => succeeded(queued)
2024-03-11T13:57:36Z INFO - [1/foo/00:succeeded(queued)] task completed
...
2024-03-11T13:57:36Z INFO - Command "set" actioned. ID=3003469a-d82d-4434-9d28-ff0950dc87d3

Would be better written like so:

2024-03-11T13:57:36Z INFO - Command "set" received. ID=3003469a-d82d-4434-9d28-ff0950dc87d3
    set(flow=['all'], flow_wait=False, outputs=[], prerequisites=[], tasks=['1/foo'])
2024-03-11T13:57:36Z INFO - [1/foo:waiting(queued)] completed output a
2024-03-11T13:57:36Z INFO - [1/foo:waiting(queued)] completed output b
2024-03-11T13:57:36Z INFO - [1/foo:waiting(queued)] setting implied output: submitted
2024-03-11T13:57:36Z INFO - [1/foo:waiting(queued)] setting implied output: started
2024-03-11T13:57:36Z INFO - [1/foo:waiting(queued)] => succeeded(queued)
2024-03-11T13:57:36Z INFO - [1/foo/00:succeeded(queued)] task completed
2024-03-11T13:57:36Z INFO - Command "set" actioned. ID=3003469a-d82d-4434-9d28-ff0950dc87d3
2024-03-11T13:57:36Z INFO - [1/bar:waiting(runahead)] added to active task pool
2024-03-11T13:57:36Z INFO - [1/bar:waiting(runahead)] => waiting
2024-03-11T13:57:36Z INFO - [1/bar:waiting] added to active task pool
2024-03-11T13:57:36Z INFO - [1/bar:waiting] => waiting(queued)

@hjoliver, would it be possible (follow-on work) to do all the output setting first, and delay the downstream consequences until the end of the routine to avoid this?

[hjoliver]

@hjoliver, would it be possible (follow-on work) to do all the output setting first, and delay the downstream consequences until the end of the routine to avoid this?

Yeah - see cylc#6018

[hjoliver]

Thanks @wxtim