Display the time it takes each vagrant ansible task to complete

Question

I'm converting a vagrant provisioner from shell to ansible and I was wondering if there's any option to show the actual time it takes to complete each task?

Ideally I want to benchmark the difference between installing multiple packages in yum using a shell: method and the in built yum: with_items method. ATM I'm sitting here with a stop watch but I need accurate times for this.

Answer 1

I've solved for timing Ansible task durations by adding a callback plugin. Callback plugins were designed to allow you to run your own arbitrary code based on events that happen in the context of an Ansible run.

The plugin I use is easily deployed by creating a callback_plugins directory and dropping a python script into it.

Here is an sample of the resulting output at the end of your playbook run:

PLAY RECAP ********************************************************************  npm_install_foo | Install node dependencies via npm ------------------- 194.92s gulp_build | Run Gulp to build ----------------------------------------- 89.99s nodejs | Update npm ---------------------------------------------------- 26.96s common | Update apt cache and upgrade base os packages ----------------- 17.78s forever | Install forever (restarts Node.js if it fails) --------------- 16.84s nodejs | Node.js | Install Node.js and npm ----------------------------- 15.11s bower | Install bower --------------------------------------------------- 9.37s Copy locally fetched repo to each instance ------------------------------ 8.03s express | Express | Install Express ------------------------------------- 8.00s 

Additionally, I prepend the shell command time to the ansible-playbook run. This nicely aggregates all of the individual task durations.

EDIT #1:

As of Ansible v2.0.0 this particular plugin ships with Ansible itself! Just add callbacks_enabled = profile_tasks to your ~/.ansible.cfg file in the [defaults] section.

EDIT #2: Since Ansible v2.1.5 callback_whitelist has been deprecated in favor of callbacks_enabled.

[defaults] callbacks_enabled = profile_tasks ... 

Answer 2

Ansible puts timestamps into its logs, so you could use that. You can switch this on using your ansible.cfg file:

[defaults] log_path = ./ansible.log 

You could also do something crude like this - create a playbook that looks like this:

--- # # Outputs a timestamp to the console # # Used for debugging/timing stuff. #  - local_action: shell date +'%F %T'   register: ts   sudo: no  - name: Timestamp   debug: msg="{{ ts.stdout }}" 

Then include that wherever you want to output a timestamp.