job submissions clobbered by interaction between set and trigger

[oliver-sanders]

A bizzare interaction between cylc set and cylc trigger can cause Cylc to revert back to submission 01, clobbering previous submissions.

This causes task state to drift from job state. It also activates the logic for cleaning out stale job log directories orphaned from a previous run, causing the old logs to be deleted.

Reproducible Example

[scheduling]
    [[graph]]
        R1 = a => b

[runtime]
    [[a]]
        script = true
    [[b]]
        script = false
        [[[events]]]
            failed handlers = """
                cylc trigger %(workflow)s//%(point)s/a && sleep 10 && cylc set %(workflow)s//%(point)s/a && cylc trigger %(workflow)s//%(point)s/a;
            """

$ cylc vip
...
INFO - [1/a:waiting(runahead)] => waiting
INFO - [1/a/01:running] => succeeded
...
INFO - [1/b:waiting(runahead)] => waiting
INFO - [1/b/01:running] => failed
...
    force_trigger_tasks(flow=[], flow_wait=False, on_resume=False, tasks=['1/a'])
INFO - Removed tasks: 1/a (flows=1)
INFO - [1/a:waiting(runahead)] => waiting
INFO - [1/a/02:running] => succeeded
...
    set(flow=[], flow_wait=False, outputs=[], prerequisites=[], tasks=['1/a'])
INFO - [1/a:waiting(runahead)] setting implied output: submitted
INFO - [1/a:waiting(runahead)] setting implied output: started
...
    force_trigger_tasks(flow=[], flow_wait=False, on_resume=False, tasks=['1/a'])
INFO - [1/a:waiting(runahead)] => waiting
INFO - [1/a/01:running] => succeeded

If you look in log/job/1/a you will only find an 01 submission, but there were actually three!

[MetRonnie]

Root cause

Triggering a after it has completed naturally causes it to first be removed (from flow=1) as per group trigger (#6395). It then runs again in flow=1. This leaves the DB in this state:

# task_outputs
cycle  name  flow_nums  outputs                                                                   
-----  ----  ---------  --------------------------------------------------------------------------
1      a     []         {"submitted": "submitted", "started": "started", "succeeded": "succeeded"}
1      a     [1]        {"submitted": "submitted", "started": "started", "succeeded": "succeeded"}

# task_states
cycle  name  flow_nums  submit_num  status   
-----  ----  ---------  ----------  ---------
1      a     [1]        2           succeeded
1      a     []         1           succeeded

cylc set looks in the DB for the historical outputs:

cylc-flow/cylc/flow/task_pool.py

Lines 2130 to 2133 in b6d124c

	trans = self._load_db_task_proxy(
	icycle, tdef, flow_nums,
	flow_wait=flow_wait, transient=True
	)

cylc-flow/cylc/flow/task_pool.py

Line 1952 in b6d124c

self._load_historical_outputs(itask)

cylc-flow/cylc/flow/task_pool.py

Lines 1743 to 1744 in b6d124c

	info = self.workflow_db_mgr.pri_dao.select_task_outputs(
	itask.tdef.name, str(itask.point))

The root cause is that select_task_outputs was only returning a single entry, the flow=none entry, because of the return format being a dict where the key is identical for both entries.

cylc-flow/cylc/flow/rundb.py

Lines 896 to 901 in b6d124c

	return {
	outputs: deserialise_set(flow_nums)
	for flow_nums, outputs in self.connect().execute(
	stmt, (name, point,)
	)
	}

And so, to cylc set, it looks like the task never ran before in flow=1.

cylc-flow/cylc/flow/task_pool.py

Lines 1771 to 1773 in b6d124c

	if not flow_seen:
	# itask never ran before in its assigned flows
	self.db_add_new_flow_rows(itask)

It thus leaves the DB in this state, clobbering the flow=1 entries which it didn't know existed:

# task_outputs
cycle  name  flow_nums  outputs                                                                                                      
-----  ----  ---------  -------------------------------------------------------------------------------------------------------------
1      a     []         {"submitted": "submitted", "started": "started", "succeeded": "succeeded"}                                   
1      a     [1]        {"submitted": "(manually completed)", "started": "(manually completed)", "succeeded": "(manually completed)"}

# task_states
cycle  name  flow_nums  submit_num  status   
-----  ----  ---------  ----------  ---------
1      a     [1]        0           succeeded
1      a     []         1           succeeded

Then when triggering the task again, it removes the task from flow=1 again by deleting the flow=none entry and updating the flow=1 entry so that it becomes flow=none, for each table. So then it thinks the submit number is 0 and thus we end up with job number 1 again.