Record all broadcast values in xtrigger return signature

[sadielbartholomew]

These changes close #3275.

Using the example xtrigger from the Issue above I now see in the suite log, as expected:

2019-08-06T20:05:28+01:00 INFO - Broadcast set:
	+ [foo.20190806T2005+01] [environment]succeeding_ONE=one
	+ [foo.20190806T2005+01] [environment]succeeding_TWO=two
	+ [foo.20190806T2005+01] [environment]succeeding_THREE=three
2019-08-06T20:05:28+01:00 INFO - [foo.20190806T2005+01] -submit-num=01, owner@host=...

Requirements 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).
• Appropriate tests are included (unit and/or functional).
• Appropriate change log entry included.
• No documentation update required.

[hjoliver]

Confirmed this results in all broadcast values getting logged (and doesn't not break the broadcast to dependent jobs, which was actually working fine!).

[hjoliver]

@sadielbartholomew - I'll change the title of this PR and the original Issue to reflect the fact that this was only a logging problem.

[hjoliver]

and doesn't not break the broadcast to dependent jobs, which was actually working fine!

Seems somewhat remarkable that this fixed the logging but did not break the broadcast 🤔

[hjoliver]

@sadielbartholomew - your change here essentially handles the N-item xtrigger return dict as N separate broadcasts of single environment variables, instead of a single broadcast of an N-item environment dict. The broadcast code is actually designed to handle the latter (as evidenced by the fact that the actual broadcast was working correctly, if not the logging). So arguably, it is the logging (/broadcast report) code that should be changed here ... although it probably doesn't really much either way because I don't think there's actually any other context - at the moment at least - in which we can broadcast multiple settings at once). We might need @matthewrmshin to chime in on this (he did the last refactor of broadcast and broadcast logging code, as I recall).

[sadielbartholomew]

Great thanks @hjoliver, I've largely responded in #3275 (comment), to record further notes on the problem itself, but just to add:

So arguably, it is the logging (/broadcast report) code that should be changed here ...

I agree; now you have pinpointed the fault, I will change it rather than make changes in another area that fix it essentially by bypassing the problem 😄. I'll then look at the tests to see if we can cover the (xtrigger) broadcast logging in a way to catch this.

[matthewrmshin]

It is not just logging, but also the database broadcast_states record, which is loaded on restart.

The fix here is good (within context). For historical reason, broadcasts settings come in as a list of nested dict, with each nested layer containing a single key: value pair. So, the method that writes the string for logging and database recording expects this data structure:

[
    {'environment': {'ONE': 'one'}},
    {'environment': {'TWO', 'two'}},
    {'environment': {'THREE', 'three'}},
]

Alternatively, we can try to modernise/modify this function (which may be a bigger can of worms):

cylc-flow/cylc/flow/broadcast_report.py

Lines 57 to 87 in cd3b526

	def get_broadcast_change_iter(modified_settings, is_cancel=False):
	"""Return an iterator of broadcast changes.
	Each broadcast change is a dict with keys:
	change, point, namespace, key, value
	"""
	if not modified_settings:
	return
	if is_cancel:
	change = CHANGE_PREFIX_CANCEL
	else:
	change = CHANGE_PREFIX_SET
	for modified_setting in sorted(modified_settings,
	key=lambda x: (x[0], x[1])):
	# sorted by (point, namespace)
	point, namespace, setting = modified_setting
	value = setting
	keys_str = ""
	while isinstance(value, dict):
	key, value = list(value.items())[0]
	if isinstance(value, dict):
	keys_str += "[" + key + "]"
	else:
	keys_str += key
	yield {
	"change": change,
	"point": point,
	"namespace": namespace,
	"key": keys_str,
	"value": str(value)}

[hjoliver]

@matthewrmshin - OK I'm happy with that. I was just flagging the fact that the code that "does the broadcast" (i.e., in the case of broadcast environment variables, writes the variables to the job environments) does handle a single dict of multiple items (like a task environment section of the config dict). However, in this comment:

... it probably doesn't really much either way because I don't think there's actually any other context - at the moment at least - in which we can broadcast multiple settings at once...

I was noting that all other uses of broadcast (i.e. setting multiple items at once using cylc broadcast) do actually result in a list of single-item dicts as your function expects.

So I agree - let's stick with @sadielbartholomew 's change then, and avoid opening another can of worms 👍

[hjoliver]

It is not just logging, but also the database broadcast_states record, which is loaded on restart.

Right, I hadn't noticed that!

[hjoliver]

Note this should be back-ported to 7.8.x, and makes a good reason to release 7.8.4 before too long.

[hjoliver]

It is not just logging, but also the database broadcast_states record, which is loaded on restart.

Worth adding a test on DB contents then, after a broadcast (could add this to the suite-state xtrigger test?).

[sadielbartholomew]

So, the method that writes the string for logging and database recording expects this data structure:

That's the impression I got from doing a git grep "put_broadcast" under cylc/flow & looking from that into current usage, which I observed to log okay in dummy suites doing standard broadcasting, hence the solution I put in & then was happy enough with after seeing it work under testing.

let's stick with @sadielbartholomew 's change then, and avoid opening another can of worms

I'm happy to go with this too, especially since we have a lot going on otherwise! We can leave the worms for later.

Note this should be back-ported to 7.8.x

Noted, I will open a counterpart PR to 7.8.x once this is nearly at the merge stage.

[sadielbartholomew]

So there's just the multi-broadcast DB test to add in (as well as a change log entry), I believe. I'll start on that after lunch. Thanks, both, for your guidance.

[sadielbartholomew]

In the new commit I added two sub-tests, under the existing suite state xtrigger test modules as Hilary suggested, to check that multiple (& all for a test case task in question) xtrigger broadcasts get recorded as they should, in the log & in the database.

The two tests pass on this branch, but fail on master, so they capture the problem as required. On master:

$ etc/bin/run-functional-tests.sh -v flakytests/xtriggers/01-suite_state.t

ok 1 - 01-suite_state-val-up
ok 2 - 01-suite_state-val
ok 3 - 01-suite_state-run-fail
ok 4 - log-grep-ok
ok 5 - suite_state.out-contains-ok
ok 6 - job-contains-ok
not ok 7 - log-contains-ok
not ok 8 - db-broadcast-states.out-contains-ok

    stdout and stderr stored in: /var/tmp/sbarth/cylctb-20190807T155459Z/xtriggers/01-suite_state
Failed 2/8 subtests 
[16:56:14]

Test Summary Report
-------------------
flakytests/xtriggers/01-suite_state.t (Wstat: 0 Tests: 8 Failed: 2)
  Failed tests:  7-8
Files=1, Tests=8, 74 wallclock secs ( 0.02 usr  0.01 sys + 16.10 cusr  6.14 csys = 22.27 CPU)
Result: FAIL

(Just noticed there is one shellchecker issue raised via Travis CI, I just need to go in address that).

[sadielbartholomew]

Testing all passing, so this should be good to go in now, unless anyone has any feedback. Thanks.

[hjoliver]

All good; thanks @sadielbartholomew 👍

[sadielbartholomew]

I'm sorting out a back port for this now & will raise it as a PR shortly.