Show Ansible timing stats at end of play

profile_tasks.py

"""
based on
  https://github.com/jlafon/ansible-profile
  https://github.com/ansible/ansible/blob/devel/lib/ansible/plugins/callback/timer.py

just throw this into a callback_plugins directory inside your playbooks directory
"""

import time
import datetime
from datetime import datetime, timedelta
import re


class CallbackModule(object):
    """
    A plugin for timing tasks
    """

    start_time = datetime.now()

    def __init__(self):
        self.stats = {}
        self.current = None

    def playbook_on_task_start(self, name, is_conditional):
        """
        Logs the start of each task
        """
        if self.current is not None:
            # Record the running time of the last executed task
            self.stats[self.current] = time.time() - self.stats[self.current]

        # Record the start time of the current task
        self.current = name
        self.stats[self.current] = time.time()

    def playbook_on_stats(self, stats):
        """
        Prints the timings
        """

        # Record the timing of the very last task
        if self.current is not None:
            self.stats[self.current] = time.time() - self.stats[self.current]

        end_time = datetime.now()
        timedelta = end_time - self.start_time

        # Sort the tasks by their running time
        results = sorted(
            self.stats.items(),
            key=lambda value: value[1],
            reverse=True,
        )

        # Just keep the top 10
        results = results[:10]

        # Print the timings
        print ("{0:~^89}".format(" Task Timings "))
        for name, elapsed in results:
            print(
                "{0:-<80}{1:->9}".format(
                    '{0} '.format(name),
                    ' {0:.02f} s'.format(elapsed),
                )
            )
        print ("{0:~>89}".format(''))
        print("{0: >90}".format(" Total (H:M:S) %s " % (re.sub(r"\.\d+$", "", str(timedelta)))))
        print("\n")