Add stats on rescued/ignored tasks (ansible#48418)

* Adding rescued/ignored tasks to stats gathering

Fixes ansible#31245

* Amend integration tests to pass

* callback/dense.py: fix too-many-format-args

* Add changelog

* Amend counter_enabled and unixy callbacks

* Fix syntax error

* Fix typo in the changelog

* Remove not needed comment

* Re-add skipped

* Add test for rescued

* Fix colors...

* Fix unstable tests?

* Add a note to the porting guide

* Re-word the note in the porting guide

Fixes ansible#20346
Fixes ansible#24525
Fixes ansible#14393

Co-authored-by: James Cammarata <[email protected]>
Co-authored-by: Martin Krizek <[email protected]>

changelogs/fragments/improved_stats.yaml

@@ -0,0 +1,2 @@
+minor_changes:
+  - Add stats on rescued/ignored tasks to play recap (https://github.com/ansible/ansible/pull/48418)

docs/docsite/rst/porting_guides/porting_guide_2.8.rst

@@ -230,6 +230,7 @@ Plugins
   ``CLIARGS.get('tags')`` and ``CLIARGS['tags']`` work as expected but you won't be able to modify
   the cli arguments at all.
 
+* Play recap now counts ``ignored`` and ``rescued`` tasks as well as ``ok``, ``changed``, ``unreachable``, ``failed`` and ``skipped`` tasks, thanks to two additional stat counters in the ``default`` callback plugin. Tasks that fail and have ``ignore_errors: yes`` set are listed as ``ignored``. Tasks that fail and then execute a rescue section are listed as ``rescued``. Note that ``rescued`` tasks are no longer counted as ``failed`` as in Ansible 2.7 (and earlier).
 
 Porting custom scripts
 ======================

lib/ansible/executor/stats.py

@@ -34,6 +34,8 @@ def __init__(self):
         self.dark = {}
         self.changed = {}
         self.skipped = {}
+        self.rescued = {}
+        self.ignored = {}
 
         # user defined stats, which can be per host or global
         self.custom = {}
@@ -63,7 +65,9 @@ def summarize(self, host):
             failures=self.failures.get(host, 0),
             unreachable=self.dark.get(host, 0),
             changed=self.changed.get(host, 0),
-            skipped=self.skipped.get(host, 0)
+            skipped=self.skipped.get(host, 0),
+            rescued=self.rescued.get(host, 0),
+            ignored=self.ignored.get(host, 0),
         )
 
     def set_custom_stats(self, which, what, host=None):

lib/ansible/plugins/callback/counter_enabled.py

@@ -85,21 +85,25 @@ def v2_playbook_on_stats(self, stats):
         for host in hosts:
             stat = stats.summarize(host)
 
-            self._display.display(u"%s : %s %s %s %s" % (
+            self._display.display(u"%s : %s %s %s %s %s %s" % (
                 hostcolor(host, stat),
                 colorize(u'ok', stat['ok'], C.COLOR_OK),
                 colorize(u'changed', stat['changed'], C.COLOR_CHANGED),
                 colorize(u'unreachable', stat['unreachable'], C.COLOR_UNREACHABLE),
-                colorize(u'failed', stat['failures'], C.COLOR_ERROR)),
+                colorize(u'failed', stat['failures'], C.COLOR_ERROR),
+                colorize(u'rescued', stat['rescued'], C.COLOR_OK),
+                colorize(u'ignored', stat['ignored'], C.COLOR_WARN)),
                 screen_only=True
             )
 
-            self._display.display(u"%s : %s %s %s %s" % (
+            self._display.display(u"%s : %s %s %s %s %s %s" % (
                 hostcolor(host, stat, False),
                 colorize(u'ok', stat['ok'], None),
                 colorize(u'changed', stat['changed'], None),
                 colorize(u'unreachable', stat['unreachable'], None),
-                colorize(u'failed', stat['failures'], None)),
+                colorize(u'failed', stat['failures'], None),
+                colorize(u'rescued', stat['rescued'], None),
+                colorize(u'ignored', stat['ignored'], None)),
                 log_only=True
             )
 

lib/ansible/plugins/callback/default.py

@@ -327,23 +327,31 @@ def v2_playbook_on_stats(self, stats):
         for h in hosts:
             t = stats.summarize(h)
 
-            self._display.display(u"%s : %s %s %s %s %s" % (
-                hostcolor(h, t),
-                colorize(u'ok', t['ok'], C.COLOR_OK),
-                colorize(u'changed', t['changed'], C.COLOR_CHANGED),
-                colorize(u'unreachable', t['unreachable'], C.COLOR_UNREACHABLE),
-                colorize(u'failed', t['failures'], C.COLOR_ERROR),
-                colorize(u'skipped', t['skipped'], C.COLOR_SKIP)),
+            self._display.display(
+                u"%s : %s %s %s %s %s %s %s" % (
+                    hostcolor(h, t),
+                    colorize(u'ok', t['ok'], C.COLOR_OK),
+                    colorize(u'changed', t['changed'], C.COLOR_CHANGED),
+                    colorize(u'unreachable', t['unreachable'], C.COLOR_UNREACHABLE),
+                    colorize(u'failed', t['failures'], C.COLOR_ERROR),
+                    colorize(u'skipped', t['skipped'], C.COLOR_SKIP),
+                    colorize(u'rescued', t['rescued'], C.COLOR_OK),
+                    colorize(u'ignored', t['ignored'], C.COLOR_WARN),
+                ),
                 screen_only=True
             )
 
-            self._display.display(u"%s : %s %s %s %s %s" % (
-                hostcolor(h, t, False),
-                colorize(u'ok', t['ok'], None),
-                colorize(u'changed', t['changed'], None),
-                colorize(u'unreachable', t['unreachable'], None),
-                colorize(u'failed', t['failures'], None),
-                colorize(u'skipped', t['skipped'], None)),
+            self._display.display(
+                u"%s : %s %s %s %s %s %s %s" % (
+                    hostcolor(h, t, False),
+                    colorize(u'ok', t['ok'], None),
+                    colorize(u'changed', t['changed'], None),
+                    colorize(u'unreachable', t['unreachable'], None),
+                    colorize(u'failed', t['failures'], None),
+                    colorize(u'skipped', t['skipped'], None),
+                    colorize(u'rescued', t['rescued'], None),
+                    colorize(u'ignored', t['ignored'], None),
+                ),
                 log_only=True
             )
 

lib/ansible/plugins/callback/dense.py

@@ -481,12 +481,16 @@ def v2_playbook_on_stats(self, stats):
         hosts = sorted(stats.processed.keys())
         for h in hosts:
             t = stats.summarize(h)
-            self._display.display(u"%s : %s %s %s %s" % (
-                hostcolor(h, t),
-                colorize(u'ok', t['ok'], C.COLOR_OK),
-                colorize(u'changed', t['changed'], C.COLOR_CHANGED),
-                colorize(u'unreachable', t['unreachable'], C.COLOR_UNREACHABLE),
-                colorize(u'failed', t['failures'], C.COLOR_ERROR)),
+            self._display.display(
+                u"%s : %s %s %s %s %s %s" % (
+                    hostcolor(h, t),
+                    colorize(u'ok', t['ok'], C.COLOR_OK),
+                    colorize(u'changed', t['changed'], C.COLOR_CHANGED),
+                    colorize(u'unreachable', t['unreachable'], C.COLOR_UNREACHABLE),
+                    colorize(u'failed', t['failures'], C.COLOR_ERROR),
+                    colorize(u'rescued', t['rescued'], C.COLOR_OK),
+                    colorize(u'ignored', t['ignored'], C.COLOR_WARN),
+                ),
                 screen_only=True
             )
 

lib/ansible/plugins/callback/selective.py

@@ -237,8 +237,8 @@ def v2_playbook_on_stats(self, stats):
             else:
                 color = 'ok'
 
-            msg = '{0}    : ok={1}\tchanged={2}\tfailed={3}\tunreachable={4}'.format(
-                host, s['ok'], s['changed'], s['failures'], s['unreachable'])
+            msg = '{0}    : ok={1}\tchanged={2}\tfailed={3}\tunreachable={4}\trescued={5}\tignored={6}'.format(
+                host, s['ok'], s['changed'], s['failures'], s['unreachable'], s['rescued'], s['ignored'])
             print(colorize(msg, color))
 
     def v2_runner_on_skipped(self, result, **kwargs):

lib/ansible/plugins/callback/slack.py

@@ -207,7 +207,7 @@ def v2_playbook_on_stats(self, stats):
         hosts = sorted(stats.processed.keys())
 
         t = prettytable.PrettyTable(['Host', 'Ok', 'Changed', 'Unreachable',
-                                     'Failures'])
+                                     'Failures', 'Rescued', 'Ignored'])
 
         failures = False
         unreachable = False
@@ -221,7 +221,7 @@ def v2_playbook_on_stats(self, stats):
                 unreachable = True
 
             t.add_row([h] + [s[k] for k in ['ok', 'changed', 'unreachable',
-                                            'failures']])
+                                            'failures', 'rescued', 'ignored']])
 
         attachments = []
         msg_items = [

lib/ansible/plugins/callback/unixy.py

@@ -173,21 +173,25 @@ def v2_playbook_on_stats(self, stats):
             # TODO how else can we display these?
             t = stats.summarize(h)
 
-            self._display.display(u"  %s : %s %s %s %s" % (
+            self._display.display(u"  %s : %s %s %s %s %s %s" % (
                 hostcolor(h, t),
                 colorize(u'ok', t['ok'], C.COLOR_OK),
                 colorize(u'changed', t['changed'], C.COLOR_CHANGED),
                 colorize(u'unreachable', t['unreachable'], C.COLOR_UNREACHABLE),
-                colorize(u'failed', t['failures'], C.COLOR_ERROR)),
+                colorize(u'failed', t['failures'], C.COLOR_ERROR),
+                colorize(u'rescued', t['rescued'], C.COLOR_OK),
+                colorize(u'ignored', t['ignored'], C.COLOR_WARN)),
                 screen_only=True
             )
 
-            self._display.display(u"  %s : %s %s %s %s" % (
+            self._display.display(u"  %s : %s %s %s %s %s %s" % (
                 hostcolor(h, t, False),
                 colorize(u'ok', t['ok'], None),
                 colorize(u'changed', t['changed'], None),
                 colorize(u'unreachable', t['unreachable'], None),
-                colorize(u'failed', t['failures'], None)),
+                colorize(u'failed', t['failures'], None),
+                colorize(u'rescued', t['rescued'], None),
+                colorize(u'ignored', t['ignored'], None)),
                 log_only=True
             )
 

lib/ansible/plugins/strategy/__init__.py

@@ -458,9 +458,6 @@ def search_handler_blocks_by_name(handler_name, handler_blocks):
                     else:
                         iterator.mark_host_failed(original_host)
 
-                    # increment the failed count for this host
-                    self._tqm._stats.increment('failures', original_host.name)
-
                     # grab the current state and if we're iterating on the rescue portion
                     # of a block then we save the failed task in a special var for use
                     # within the rescue/always
@@ -470,15 +467,19 @@ def search_handler_blocks_by_name(handler_name, handler_blocks):
                         self._tqm._failed_hosts[original_host.name] = True
 
                     if state and iterator.get_active_state(state).run_state == iterator.ITERATING_RESCUE:
+                        self._tqm._stats.increment('rescued', original_host.name)
                         self._variable_manager.set_nonpersistent_facts(
                             original_host,
                             dict(
                                 ansible_failed_task=original_task.serialize(),
                                 ansible_failed_result=task_result._result,
                             ),
                         )
+                    else:
+                        self._tqm._stats.increment('failures', original_host.name)
                 else:
                     self._tqm._stats.increment('ok', original_host.name)
+                    self._tqm._stats.increment('ignored', original_host.name)
                     if 'changed' in task_result._result and task_result._result['changed']:
                         self._tqm._stats.increment('changed', original_host.name)
                 self._tqm.send_callback('v2_runner_on_failed', task_result, ignore_errors=ignore_errors)

test/integration/targets/callback_default/callback_default.out.default.stdout

@@ -22,6 +22,12 @@ changed: [testhost] => (item=foo-1)
 changed: [testhost] => (item=foo-2)
 changed: [testhost] => (item=foo-3)
 
+TASK [EXPECTED FAILURE Failed task to be rescued] ******************************
+fatal: [testhost]: FAILED! => {"changed": false, "msg": "Failed as requested from task"}
+
+TASK [Rescue task] *************************************************************
+changed: [testhost]
+
 RUNNING HANDLER [Test handler 1] ***********************************************
 changed: [testhost]
 
@@ -40,5 +46,5 @@ TASK [Second free task] ********************************************************
 changed: [testhost]
 
 PLAY RECAP *********************************************************************
-testhost                   : ok=10   changed=7    unreachable=0    failed=0    skipped=1   
+testhost                   : ok=11   changed=8    unreachable=0    failed=0    skipped=1    rescued=1    ignored=1   
 

test/integration/targets/callback_default/callback_default.out.failed_to_stderr.stderr

@@ -1,3 +1,4 @@
 + ansible-playbook -i inventory test.yml
 ++ set +x
 fatal: [testhost]: FAILED! => {"changed": false, "msg": "no reason"}
+fatal: [testhost]: FAILED! => {"changed": false, "msg": "Failed as requested from task"}

test/integration/targets/callback_default/callback_default.out.failed_to_stderr.stdout

@@ -21,6 +21,11 @@ changed: [testhost] => (item=foo-1)
 changed: [testhost] => (item=foo-2)
 changed: [testhost] => (item=foo-3)
 
+TASK [EXPECTED FAILURE Failed task to be rescued] ******************************
+
+TASK [Rescue task] *************************************************************
+changed: [testhost]
+
 RUNNING HANDLER [Test handler 1] ***********************************************
 changed: [testhost]
 
@@ -39,5 +44,5 @@ TASK [Second free task] ********************************************************
 changed: [testhost]
 
 PLAY RECAP *********************************************************************
-testhost                   : ok=10   changed=7    unreachable=0    failed=0    skipped=1   
+testhost                   : ok=11   changed=8    unreachable=0    failed=0    skipped=1    rescued=1    ignored=1   
 

test/integration/targets/callback_default/callback_default.out.hide_ok.stdout

@@ -19,6 +19,12 @@ changed: [testhost] => (item=foo-1)
 changed: [testhost] => (item=foo-2)
 changed: [testhost] => (item=foo-3)
 
+TASK [EXPECTED FAILURE Failed task to be rescued] ******************************
+fatal: [testhost]: FAILED! => {"changed": false, "msg": "Failed as requested from task"}
+
+TASK [Rescue task] *************************************************************
+changed: [testhost]
+
 RUNNING HANDLER [Test handler 1] ***********************************************
 changed: [testhost]
 
@@ -34,5 +40,5 @@ TASK [Second free task] ********************************************************
 changed: [testhost]
 
 PLAY RECAP *********************************************************************
-testhost                   : ok=10   changed=7    unreachable=0    failed=0    skipped=1   
+testhost                   : ok=11   changed=8    unreachable=0    failed=0    skipped=1    rescued=1    ignored=1   
 

test/integration/targets/callback_default/callback_default.out.hide_skipped.stdout

@@ -19,6 +19,12 @@ changed: [testhost] => (item=foo-1)
 changed: [testhost] => (item=foo-2)
 changed: [testhost] => (item=foo-3)
 
+TASK [EXPECTED FAILURE Failed task to be rescued] ******************************
+fatal: [testhost]: FAILED! => {"changed": false, "msg": "Failed as requested from task"}
+
+TASK [Rescue task] *************************************************************
+changed: [testhost]
+
 RUNNING HANDLER [Test handler 1] ***********************************************
 changed: [testhost]
 
@@ -37,5 +43,5 @@ TASK [Second free task] ********************************************************
 changed: [testhost]
 
 PLAY RECAP *********************************************************************
-testhost                   : ok=10   changed=7    unreachable=0    failed=0    skipped=1   
+testhost                   : ok=11   changed=8    unreachable=0    failed=0    skipped=1    rescued=1    ignored=1   
 

test/integration/targets/callback_default/callback_default.out.hide_skipped_ok.stdout

@@ -16,6 +16,12 @@ changed: [testhost] => (item=foo-1)
 changed: [testhost] => (item=foo-2)
 changed: [testhost] => (item=foo-3)
 
+TASK [EXPECTED FAILURE Failed task to be rescued] ******************************
+fatal: [testhost]: FAILED! => {"changed": false, "msg": "Failed as requested from task"}
+
+TASK [Rescue task] *************************************************************
+changed: [testhost]
+
 RUNNING HANDLER [Test handler 1] ***********************************************
 changed: [testhost]
 
@@ -31,5 +37,5 @@ TASK [Second free task] ********************************************************
 changed: [testhost]
 
 PLAY RECAP *********************************************************************
-testhost                   : ok=10   changed=7    unreachable=0    failed=0    skipped=1   
+testhost                   : ok=11   changed=8    unreachable=0    failed=0    skipped=1    rescued=1    ignored=1   
 

test/integration/targets/callback_default/test.yml

@@ -33,6 +33,14 @@
         - 3
       loop_control:
         label: foo-{{ item }}
+
+    - block:
+        - name: EXPECTED FAILURE Failed task to be rescued
+          fail:
+      rescue:
+        - name: Rescue task
+          command: echo rescued
+
   handlers:
     - name: Test handler 1
       command: echo foo