Merge pull request #14661 from jjshoe/fix-up-profile-tasks

Update the profile task callback plugin to include a fix for duplicate named tasks. Added additional features to adjust the number of tasks output and the sort order.

lib/ansible/plugins/callback/profile_tasks.py

@@ -1,3 +1,4 @@
+# (C) 2016, Joel, http://github.com/jjshoe 
 # (C) 2015, Tom Paine, <github@aioue.net>
 # (C) 2014, Jharrod LaFon, @JharrodLaFon
 # (C) 2012-2013, Michael DeHaan, <michael.dehaan@gmail.com>
@@ -22,6 +23,8 @@
 from __future__ import (absolute_import, division, print_function)
 __metaclass__ = type
 
+import collections
+import os
 import time
 
 from ansible.plugins.callback import CallbackBase
@@ -49,7 +52,7 @@ def filled(msg, fchar="*"):
 
 def timestamp(self):
     if self.current is not None:
-        self.stats[self.current] = time.time() - self.stats[self.current]
+        self.stats[self.current]['time'] = time.time() - self.stats[self.current]['time']
 
 
 def tasktime():
@@ -72,12 +75,22 @@ class CallbackModule(CallbackBase):
     CALLBACK_NEEDS_WHITELIST = True
 
     def __init__(self):
-        self.stats = {}
+        self.stats = collections.OrderedDict()
         self.current = None
+        self.sort_order = os.getenv('PROFILE_TASKS_SORT_ORDER', True)
+        self.task_output_limit = os.getenv('PROFILE_TASKS_TASK_OUTPUT_LIMIT', 20)
+
+        if self.sort_order == 'ascending':
+            self.sort_order = False;
+
+        if self.task_output_limit == 'all':
+            self.task_output_limit = None
+        else:
+            self.task_output_limit = int(self.task_output_limit) 
 
         super(CallbackModule, self).__init__()
 
-    def _record_task(self, name):
+    def _record_task(self, task):
         """
         Logs the start of each task
         """
@@ -85,14 +98,14 @@ class CallbackModule(CallbackBase):
         timestamp(self)
 
         # Record the start time of the current task
-        self.current = name
-        self.stats[self.current] = time.time()
+        self.current = task._uuid
+        self.stats[self.current] = {'time': time.time(), 'name': task.get_name(), 'path': task.get_path()}
 
-    def playbook_on_task_start(self, name, is_conditional):
-        self._record_task(name)
+    def v2_playbook_on_task_start(self, task, is_conditional):
+        self._record_task(task)
 
     def v2_playbook_on_handler_task_start(self, task):
-        self._record_task('HANDLER: ' + task.name)
+        self._record_task(task)
 
     def playbook_on_setup(self):
         self._display.display(tasktime())
@@ -103,21 +116,25 @@ class CallbackModule(CallbackBase):
 
         timestamp(self)
 
-        # Sort the tasks by their running time
-        results = sorted(
-            self.stats.items(),
-            key=lambda value: value[1],
-            reverse=True,
-        )
+        results = self.stats.items() 
+
+        # Sort the tasks by the specified sort
+        if self.sort_order != 'none':
+            results = sorted(
+                self.stats.iteritems(),
+                key=lambda x:x[1]['time'],
+                reverse=self.sort_order,
+            )
 
-        # Just keep the top 20
-        results = results[:20]
+        # Display the number of tasks specified or the default of 20 
+        results = results[:self.task_output_limit]
 
         # Print the timings
-        for name, elapsed in results:
+        for uuid, result in results:
             self._display.display(
-                "{0:-<70}{1:->9}".format(
-                    '{0} '.format(name),
-                    ' {0:.02f}s'.format(elapsed),
+                "{0:-<70}{1:-<70}{2:->9}".format(
+                    '{0} '.format(result['path']),
+                    '{0} '.format(result['name']),
+                    ' {0:.02f}s'.format(result['time']),
                 )
             )

lib/ansible/plugins/callback/profile_tasks.rst

@@ -15,6 +15,11 @@ Add ``profile_tasks`` to the ``callback_whitelist`` in ``ansible.cfg``.
 
 Run playbooks as normal.
 
+Certain options are configurable using environment variables. You can specify ``ascending`` or ``none`` for
+the environment variable ``PROFILE_TASKS_SORT_ORDER`` to adjust sorting output. If you want to see more than
+20 tasks in the output you can set ``PROFILE_TASKS_TASK_OUTPUT_LIMIT`` to any number, or the special value
+``all`` to get a list of all tasks.
+
 Features
 --------
 
@@ -53,15 +58,11 @@ No more wondering how old the results in a terminal window are.
        PLAY RECAP ******************************************************************** 
        Thursday 11 June 2016  22:51:00 +0100 (0:00:01.011)       0:00:43.247 *********
        ===============================================================================
-       really slow task  | Download project packages----------------------------11.61s
-       security | Really slow security policies----------------------------------7.03s
-       common-base | Install core system dependencies----------------------------3.62s
-       common | Install pip------------------------------------------------------3.60s
-       common | Install boto-----------------------------------------------------3.57s
-       nginx | Install nginx-----------------------------------------------------3.41s
-       serf | Install system dependencies----------------------------------------3.38s
-       duo_security | Install Duo Unix SSH Integration---------------------------3.37s
-       loggly | Install TLS version----------------------------------------------3.36s
+       /home/bob/ansible/roles/old_and_slow/tasks/main.yml:4 ----------------old_and_slow : install tons of packages -------------------------------- 20.03s
+       /home/bob/ansible/roles/db/tasks/main.yml:4 --------------------------db : second task to run ------------------------------------------------- 2.03s
+       None -----------------------------------------------------------------setup ------------------------------------------------------------------- 0.42s
+       /home/bob/ansible/roles/www/tasks/main.yml:1 -------------------------www : first task to run ------------------------------------------------- 0.03s
+       /home/bob/ansible/roles/fast_task.yml:1 ------------------------------fast_task : first task to run ------------------------------------------- 0.01s
 
 Compatibility
 -------------