From 5708894f909cf8d44faf94fc8d57dd71d4877cb0 Mon Sep 17 00:00:00 2001 From: Andrew Gaffney Date: Mon, 13 Aug 2018 08:21:33 -0500 Subject: [PATCH] Bugfixes and integration tests for 'default' callback plugin * display 'changed' tasks when hiding 'ok' tasks * display proper task title for handlers (fixes #44007) --- lib/ansible/plugins/callback/default.py | 109 +++++++++++------- .../targets/callback_default/aliases | 1 + .../callback_default.out.default.stderr | 2 + .../callback_default.out.default.stdout | 44 +++++++ ...llback_default.out.failed_to_stderr.stderr | 3 + ...llback_default.out.failed_to_stderr.stdout | 43 +++++++ .../callback_default.out.hide_ok.stderr | 2 + .../callback_default.out.hide_ok.stdout | 38 ++++++ .../callback_default.out.hide_skipped.stderr | 2 + .../callback_default.out.hide_skipped.stdout | 41 +++++++ ...allback_default.out.hide_skipped_ok.stderr | 2 + ...allback_default.out.hide_skipped_ok.stdout | 35 ++++++ .../targets/callback_default/runme.sh | 107 +++++++++++++++++ .../targets/callback_default/test.yml | 60 ++++++++++ 14 files changed, 445 insertions(+), 44 deletions(-) create mode 100644 test/integration/targets/callback_default/aliases create mode 100644 test/integration/targets/callback_default/callback_default.out.default.stderr create mode 100644 test/integration/targets/callback_default/callback_default.out.default.stdout create mode 100644 test/integration/targets/callback_default/callback_default.out.failed_to_stderr.stderr create mode 100644 test/integration/targets/callback_default/callback_default.out.failed_to_stderr.stdout create mode 100644 test/integration/targets/callback_default/callback_default.out.hide_ok.stderr create mode 100644 test/integration/targets/callback_default/callback_default.out.hide_ok.stdout create mode 100644 test/integration/targets/callback_default/callback_default.out.hide_skipped.stderr create mode 100644 test/integration/targets/callback_default/callback_default.out.hide_skipped.stdout create mode 100644 test/integration/targets/callback_default/callback_default.out.hide_skipped_ok.stderr create mode 100644 test/integration/targets/callback_default/callback_default.out.hide_skipped_ok.stdout create mode 100755 test/integration/targets/callback_default/runme.sh create mode 100644 test/integration/targets/callback_default/test.yml diff --git a/lib/ansible/plugins/callback/default.py b/lib/ansible/plugins/callback/default.py index 71d892da9a0..f444a42d92b 100644 --- a/lib/ansible/plugins/callback/default.py +++ b/lib/ansible/plugins/callback/default.py @@ -54,6 +54,7 @@ class CallbackModule(CallbackBase): self._play = None self._last_task_banner = None self._last_task_name = None + self._task_type_cache = {} super(CallbackModule, self).__init__() def set_options(self, task_keys=None, var_options=None, direct=None): @@ -96,38 +97,42 @@ class CallbackModule(CallbackBase): def v2_runner_on_ok(self, result): - if self.display_ok_hosts: - - delegated_vars = result._result.get('_ansible_delegated_vars', None) + delegated_vars = result._result.get('_ansible_delegated_vars', None) + if isinstance(result._task, TaskInclude): + return + elif result._result.get('changed', False): if self._last_task_banner != result._task._uuid: self._print_task_banner(result._task) - if isinstance(result._task, TaskInclude): - return - elif result._result.get('changed', False): - if delegated_vars: - msg = "changed: [%s -> %s]" % (result._host.get_name(), delegated_vars['ansible_host']) - else: - msg = "changed: [%s]" % result._host.get_name() - color = C.COLOR_CHANGED + if delegated_vars: + msg = "changed: [%s -> %s]" % (result._host.get_name(), delegated_vars['ansible_host']) else: - if delegated_vars: - msg = "ok: [%s -> %s]" % (result._host.get_name(), delegated_vars['ansible_host']) - else: - msg = "ok: [%s]" % result._host.get_name() - color = C.COLOR_OK + msg = "changed: [%s]" % result._host.get_name() + color = C.COLOR_CHANGED + else: + if not self.display_ok_hosts: + return - self._handle_warnings(result._result) + if self._last_task_banner != result._task._uuid: + self._print_task_banner(result._task) - if result._task.loop and 'results' in result._result: - self._process_items(result) + if delegated_vars: + msg = "ok: [%s -> %s]" % (result._host.get_name(), delegated_vars['ansible_host']) else: - self._clean_results(result._result, result._task.action) + msg = "ok: [%s]" % result._host.get_name() + color = C.COLOR_OK - if (self._display.verbosity > 0 or '_ansible_verbose_always' in result._result) and '_ansible_verbose_override' not in result._result: - msg += " => %s" % (self._dump_results(result._result),) - self._display.display(msg, color=color) + self._handle_warnings(result._result) + + if result._task.loop and 'results' in result._result: + self._process_items(result) + else: + self._clean_results(result._result, result._task.action) + + if (self._display.verbosity > 0 or '_ansible_verbose_always' in result._result) and '_ansible_verbose_override' not in result._result: + msg += " => %s" % (self._dump_results(result._result),) + self._display.display(msg, color=color) def v2_runner_on_skipped(self, result): @@ -165,6 +170,15 @@ class CallbackModule(CallbackBase): self._display.banner("NO MORE HOSTS LEFT") def v2_playbook_on_task_start(self, task, is_conditional): + self._task_start(task, prefix='TASK') + + def _task_start(self, task, prefix=None): + # Cache output prefix for task if provided + # This is needed to properly display 'RUNNING HANDLER' and similar + # when hiding skipped/ok task results + if prefix is not None: + self._task_type_cache[task._uuid] = prefix + # Preserve task name, as all vars may not be available for templating # when we need it later if self._play.strategy == 'free': @@ -192,12 +206,14 @@ class CallbackModule(CallbackBase): args = u', '.join(u'%s=%s' % a for a in task.args.items()) args = u' %s' % args + prefix = self._task_type_cache.get(task._uuid, 'TASK') + # Use cached task name task_name = self._last_task_name if task_name is None: task_name = task.get_name().strip() - self._display.banner(u"TASK [%s%s]" % (task_name, args)) + self._display.banner(u"%s [%s%s]" % (prefix, task_name, args)) if self._display.verbosity >= 2: path = task.get_path() if path: @@ -206,10 +222,10 @@ class CallbackModule(CallbackBase): self._last_task_banner = task._uuid def v2_playbook_on_cleanup_task_start(self, task): - self._display.banner("CLEANUP TASK [%s]" % task.get_name().strip()) + self._task_start(task, prefix='CLEANUP TASK') def v2_playbook_on_handler_task_start(self, task): - self._display.banner("RUNNING HANDLER [%s]" % task.get_name().strip()) + self._task_start(task, prefix='RUNNING HANDLER') def v2_playbook_on_play_start(self, play): name = play.get_name().strip() @@ -239,31 +255,36 @@ class CallbackModule(CallbackBase): def v2_runner_item_on_ok(self, result): - if self.display_ok_hosts: + delegated_vars = result._result.get('_ansible_delegated_vars', None) + self._clean_results(result._result, result._task.action) + if isinstance(result._task, TaskInclude): + return + elif result._result.get('changed', False): if self._last_task_banner != result._task._uuid: self._print_task_banner(result._task) - delegated_vars = result._result.get('_ansible_delegated_vars', None) - self._clean_results(result._result, result._task.action) - if isinstance(result._task, TaskInclude): + msg = 'changed' + color = C.COLOR_CHANGED + else: + if not self.display_ok_hosts: return - elif result._result.get('changed', False): - msg = 'changed' - color = C.COLOR_CHANGED - else: - msg = 'ok' - color = C.COLOR_OK - if delegated_vars: - msg += ": [%s -> %s]" % (result._host.get_name(), delegated_vars['ansible_host']) - else: - msg += ": [%s]" % result._host.get_name() + if self._last_task_banner != result._task._uuid: + self._print_task_banner(result._task) - msg += " => (item=%s)" % (self._get_item_label(result._result),) + msg = 'ok' + color = C.COLOR_OK - if (self._display.verbosity > 0 or '_ansible_verbose_always' in result._result) and '_ansible_verbose_override' not in result._result: - msg += " => %s" % self._dump_results(result._result) - self._display.display(msg, color=color) + if delegated_vars: + msg += ": [%s -> %s]" % (result._host.get_name(), delegated_vars['ansible_host']) + else: + msg += ": [%s]" % result._host.get_name() + + msg += " => (item=%s)" % (self._get_item_label(result._result),) + + if (self._display.verbosity > 0 or '_ansible_verbose_always' in result._result) and '_ansible_verbose_override' not in result._result: + msg += " => %s" % self._dump_results(result._result) + self._display.display(msg, color=color) def v2_runner_item_on_failed(self, result): if self._last_task_banner != result._task._uuid: diff --git a/test/integration/targets/callback_default/aliases b/test/integration/targets/callback_default/aliases new file mode 100644 index 00000000000..b59832142f2 --- /dev/null +++ b/test/integration/targets/callback_default/aliases @@ -0,0 +1 @@ +shippable/posix/group3 diff --git a/test/integration/targets/callback_default/callback_default.out.default.stderr b/test/integration/targets/callback_default/callback_default.out.default.stderr new file mode 100644 index 00000000000..0cbea93f20d --- /dev/null +++ b/test/integration/targets/callback_default/callback_default.out.default.stderr @@ -0,0 +1,2 @@ ++ ansible-playbook -i ../../inventory test.yml +++ set +x diff --git a/test/integration/targets/callback_default/callback_default.out.default.stdout b/test/integration/targets/callback_default/callback_default.out.default.stdout new file mode 100644 index 00000000000..fe2068ada9b --- /dev/null +++ b/test/integration/targets/callback_default/callback_default.out.default.stdout @@ -0,0 +1,44 @@ + +PLAY [testhost] **************************************************************** + +TASK [Changed task] ************************************************************ +changed: [testhost] + +TASK [Ok task] ***************************************************************** +ok: [testhost] + +TASK [Failed task] ************************************************************* +fatal: [testhost]: FAILED! => {"changed": false, "msg": "no reason"} +...ignoring + +TASK [Skipped task] ************************************************************ +skipping: [testhost] + +TASK [Task with var in name (foo bar)] ***************************************** +changed: [testhost] + +TASK [Loop task] *************************************************************** +changed: [testhost] => (item=foo-1) +changed: [testhost] => (item=foo-2) +changed: [testhost] => (item=foo-3) + +RUNNING HANDLER [Test handler 1] *********************************************** +changed: [testhost] + +RUNNING HANDLER [Test handler 2] *********************************************** +ok: [testhost] + +RUNNING HANDLER [Test handler 3] *********************************************** +changed: [testhost] + +PLAY [testhost] **************************************************************** + +TASK [First free task] ********************************************************* +changed: [testhost] + +TASK [Second free task] ******************************************************** +changed: [testhost] + +PLAY RECAP ********************************************************************* +testhost : ok=10 changed=7 unreachable=0 failed=0 + diff --git a/test/integration/targets/callback_default/callback_default.out.failed_to_stderr.stderr b/test/integration/targets/callback_default/callback_default.out.failed_to_stderr.stderr new file mode 100644 index 00000000000..ac6e7d5e1f2 --- /dev/null +++ b/test/integration/targets/callback_default/callback_default.out.failed_to_stderr.stderr @@ -0,0 +1,3 @@ ++ ansible-playbook -i ../../inventory test.yml +++ set +x +fatal: [testhost]: FAILED! => {"changed": false, "msg": "no reason"} diff --git a/test/integration/targets/callback_default/callback_default.out.failed_to_stderr.stdout b/test/integration/targets/callback_default/callback_default.out.failed_to_stderr.stdout new file mode 100644 index 00000000000..1489c702bce --- /dev/null +++ b/test/integration/targets/callback_default/callback_default.out.failed_to_stderr.stdout @@ -0,0 +1,43 @@ + +PLAY [testhost] **************************************************************** + +TASK [Changed task] ************************************************************ +changed: [testhost] + +TASK [Ok task] ***************************************************************** +ok: [testhost] + +TASK [Failed task] ************************************************************* +...ignoring + +TASK [Skipped task] ************************************************************ +skipping: [testhost] + +TASK [Task with var in name (foo bar)] ***************************************** +changed: [testhost] + +TASK [Loop task] *************************************************************** +changed: [testhost] => (item=foo-1) +changed: [testhost] => (item=foo-2) +changed: [testhost] => (item=foo-3) + +RUNNING HANDLER [Test handler 1] *********************************************** +changed: [testhost] + +RUNNING HANDLER [Test handler 2] *********************************************** +ok: [testhost] + +RUNNING HANDLER [Test handler 3] *********************************************** +changed: [testhost] + +PLAY [testhost] **************************************************************** + +TASK [First free task] ********************************************************* +changed: [testhost] + +TASK [Second free task] ******************************************************** +changed: [testhost] + +PLAY RECAP ********************************************************************* +testhost : ok=10 changed=7 unreachable=0 failed=0 + diff --git a/test/integration/targets/callback_default/callback_default.out.hide_ok.stderr b/test/integration/targets/callback_default/callback_default.out.hide_ok.stderr new file mode 100644 index 00000000000..0cbea93f20d --- /dev/null +++ b/test/integration/targets/callback_default/callback_default.out.hide_ok.stderr @@ -0,0 +1,2 @@ ++ ansible-playbook -i ../../inventory test.yml +++ set +x diff --git a/test/integration/targets/callback_default/callback_default.out.hide_ok.stdout b/test/integration/targets/callback_default/callback_default.out.hide_ok.stdout new file mode 100644 index 00000000000..297662b94c6 --- /dev/null +++ b/test/integration/targets/callback_default/callback_default.out.hide_ok.stdout @@ -0,0 +1,38 @@ + +PLAY [testhost] **************************************************************** + +TASK [Changed task] ************************************************************ +changed: [testhost] + +TASK [Failed task] ************************************************************* +fatal: [testhost]: FAILED! => {"changed": false, "msg": "no reason"} +...ignoring + +TASK [Skipped task] ************************************************************ +skipping: [testhost] + +TASK [Task with var in name (foo bar)] ***************************************** +changed: [testhost] + +TASK [Loop task] *************************************************************** +changed: [testhost] => (item=foo-1) +changed: [testhost] => (item=foo-2) +changed: [testhost] => (item=foo-3) + +RUNNING HANDLER [Test handler 1] *********************************************** +changed: [testhost] + +RUNNING HANDLER [Test handler 3] *********************************************** +changed: [testhost] + +PLAY [testhost] **************************************************************** + +TASK [First free task] ********************************************************* +changed: [testhost] + +TASK [Second free task] ******************************************************** +changed: [testhost] + +PLAY RECAP ********************************************************************* +testhost : ok=10 changed=7 unreachable=0 failed=0 + diff --git a/test/integration/targets/callback_default/callback_default.out.hide_skipped.stderr b/test/integration/targets/callback_default/callback_default.out.hide_skipped.stderr new file mode 100644 index 00000000000..0cbea93f20d --- /dev/null +++ b/test/integration/targets/callback_default/callback_default.out.hide_skipped.stderr @@ -0,0 +1,2 @@ ++ ansible-playbook -i ../../inventory test.yml +++ set +x diff --git a/test/integration/targets/callback_default/callback_default.out.hide_skipped.stdout b/test/integration/targets/callback_default/callback_default.out.hide_skipped.stdout new file mode 100644 index 00000000000..2b2c4dadfd9 --- /dev/null +++ b/test/integration/targets/callback_default/callback_default.out.hide_skipped.stdout @@ -0,0 +1,41 @@ + +PLAY [testhost] **************************************************************** + +TASK [Changed task] ************************************************************ +changed: [testhost] + +TASK [Ok task] ***************************************************************** +ok: [testhost] + +TASK [Failed task] ************************************************************* +fatal: [testhost]: FAILED! => {"changed": false, "msg": "no reason"} +...ignoring + +TASK [Task with var in name (foo bar)] ***************************************** +changed: [testhost] + +TASK [Loop task] *************************************************************** +changed: [testhost] => (item=foo-1) +changed: [testhost] => (item=foo-2) +changed: [testhost] => (item=foo-3) + +RUNNING HANDLER [Test handler 1] *********************************************** +changed: [testhost] + +RUNNING HANDLER [Test handler 2] *********************************************** +ok: [testhost] + +RUNNING HANDLER [Test handler 3] *********************************************** +changed: [testhost] + +PLAY [testhost] **************************************************************** + +TASK [First free task] ********************************************************* +changed: [testhost] + +TASK [Second free task] ******************************************************** +changed: [testhost] + +PLAY RECAP ********************************************************************* +testhost : ok=10 changed=7 unreachable=0 failed=0 + diff --git a/test/integration/targets/callback_default/callback_default.out.hide_skipped_ok.stderr b/test/integration/targets/callback_default/callback_default.out.hide_skipped_ok.stderr new file mode 100644 index 00000000000..0cbea93f20d --- /dev/null +++ b/test/integration/targets/callback_default/callback_default.out.hide_skipped_ok.stderr @@ -0,0 +1,2 @@ ++ ansible-playbook -i ../../inventory test.yml +++ set +x diff --git a/test/integration/targets/callback_default/callback_default.out.hide_skipped_ok.stdout b/test/integration/targets/callback_default/callback_default.out.hide_skipped_ok.stdout new file mode 100644 index 00000000000..e50f95736e0 --- /dev/null +++ b/test/integration/targets/callback_default/callback_default.out.hide_skipped_ok.stdout @@ -0,0 +1,35 @@ + +PLAY [testhost] **************************************************************** + +TASK [Changed task] ************************************************************ +changed: [testhost] + +TASK [Failed task] ************************************************************* +fatal: [testhost]: FAILED! => {"changed": false, "msg": "no reason"} +...ignoring + +TASK [Task with var in name (foo bar)] ***************************************** +changed: [testhost] + +TASK [Loop task] *************************************************************** +changed: [testhost] => (item=foo-1) +changed: [testhost] => (item=foo-2) +changed: [testhost] => (item=foo-3) + +RUNNING HANDLER [Test handler 1] *********************************************** +changed: [testhost] + +RUNNING HANDLER [Test handler 3] *********************************************** +changed: [testhost] + +PLAY [testhost] **************************************************************** + +TASK [First free task] ********************************************************* +changed: [testhost] + +TASK [Second free task] ******************************************************** +changed: [testhost] + +PLAY RECAP ********************************************************************* +testhost : ok=10 changed=7 unreachable=0 failed=0 + diff --git a/test/integration/targets/callback_default/runme.sh b/test/integration/targets/callback_default/runme.sh new file mode 100755 index 00000000000..a10b18c9059 --- /dev/null +++ b/test/integration/targets/callback_default/runme.sh @@ -0,0 +1,107 @@ +#!/usr/bin/env bash + +# This test compares "known good" output with various settings against output +# with the current code. It's brittle by nature, but this is probably the +# "best" approach possible. +# +# Notes: +# * options passed to this script (such as -v) are ignored, as they would change +# the output and break the test +# * the number of asterisks after a "banner" differs depending on the number of +# columns on the TTY, so we must adjust the columns for the current session +# for consistency + +set -eux + +run_test() { + local testname=$1 + + # The shenanigans with redirection and 'tee' are to capture STDOUT and + # STDERR separately while still displaying both to the console + { ansible-playbook -i ../../inventory test.yml \ + > >(set +x; tee "${OUTFILE}.${testname}.stdout"); } \ + 2> >(set +x; tee "${OUTFILE}.${testname}.stderr" >&2) + diff -u "${ORIGFILE}.${testname}.stdout" "${OUTFILE}.${testname}.stdout" || diff_failure + diff -u "${ORIGFILE}.${testname}.stderr" "${OUTFILE}.${testname}.stderr" || diff_failure +} + +diff_failure() { + if [[ $INIT = 0 ]]; then + echo "FAILURE...diff mismatch!" + exit 1 + fi +} + +cleanup() { + if [[ $INIT = 0 ]]; then + rm -rf "${OUTFILE}.*" + fi + # Restore TTY cols + if [[ -n ${TTY_COLS:-} ]]; then + stty cols "${TTY_COLS}" + fi +} + +adjust_tty_cols() { + if [[ -t 1 ]]; then + # Preserve existing TTY cols + TTY_COLS=$( stty -a | grep -Eo '; columns [0-9]+;' | cut -d';' -f2 | cut -d' ' -f3 ) + # Override TTY cols to make comparing ansible-playbook output easier + # This value matches the default in the code when there is no TTY + stty cols 79 + fi +} + +BASEFILE=callback_default.out + +ORIGFILE="${BASEFILE}" +OUTFILE="${BASEFILE}.new" + +trap 'cleanup' EXIT + +# The --init flag will (re)generate the "good" output files used by the tests +INIT=0 +if [[ ${1:-} == "--init" ]]; then + shift + OUTFILE=$ORIGFILE + INIT=1 +fi + +adjust_tty_cols + +# Force the 'default' callback plugin, since that's what we're testing +export ANSIBLE_STDOUT_CALLBACK=default +# Disable color in output for consistency +export ANSIBLE_FORCE_COLOR=0 +export ANSIBLE_NOCOLOR=1 + +# Default settings +export DISPLAY_SKIPPED_HOSTS=1 +export ANSIBLE_DISPLAY_OK_HOSTS=1 +export ANSIBLE_DISPLAY_FAILED_STDERR=0 + +run_test default + +# Hide skipped +export DISPLAY_SKIPPED_HOSTS=0 + +run_test hide_skipped + +# Hide skipped/ok +export DISPLAY_SKIPPED_HOSTS=0 +export ANSIBLE_DISPLAY_OK_HOSTS=0 + +run_test hide_skipped_ok + +# Hide ok +export DISPLAY_SKIPPED_HOSTS=1 +export ANSIBLE_DISPLAY_OK_HOSTS=0 + +run_test hide_ok + +# Failed to stderr +export DISPLAY_SKIPPED_HOSTS=1 +export ANSIBLE_DISPLAY_OK_HOSTS=1 +export ANSIBLE_DISPLAY_FAILED_STDERR=1 + +run_test failed_to_stderr diff --git a/test/integration/targets/callback_default/test.yml b/test/integration/targets/callback_default/test.yml new file mode 100644 index 00000000000..c503a5edbe2 --- /dev/null +++ b/test/integration/targets/callback_default/test.yml @@ -0,0 +1,60 @@ +--- +- hosts: testhost + gather_facts: no + vars: + foo: foo bar + tasks: + - name: Changed task + command: echo foo + changed_when: true + notify: test handlers + + - name: Ok task + command: echo foo + changed_when: false + + - name: Failed task + fail: + msg: no reason + ignore_errors: yes + + - name: Skipped task + command: echo foo + when: false + + - name: Task with var in name ({{ foo }}) + command: echo foo + + - name: Loop task + command: echo foo + loop: + - 1 + - 2 + - 3 + loop_control: + label: foo-{{ item }} + handlers: + - name: Test handler 1 + command: echo foo + listen: test handlers + + - name: Test handler 2 + command: echo foo + changed_when: false + listen: test handlers + + - name: Test handler 3 + command: echo foo + listen: test handlers + +# An issue was found previously for tasks in a play using strategy 'free' after +# a non-'free' play in the same playbook, so we protect against a regression. +- hosts: testhost + gather_facts: no + strategy: free + tasks: + - name: First free task + command: echo foo + + - name: Second free task + command: echo foo