Ansible / How to measure command duration
For some reasons, you might end up in a situation, when you need to measure the time some command spent on running. I had to do this some years ago running DB migrations during deploy with Ansible (I know this is not great solution, but that was PHP 😀).
If you only want to know how long each task runs, it’s pretty easy: just add to ansible.cfg
profile_tasks, like this:
[defaults]
callback_whitelist = profile_tasks
And in the end of the ansible-playbook
run you will have summary on how long each task was running, example:
Sunday 05 January 2025 14:15:42 +0200 (0:00:20.028) 0:00:30.058 ********
===============================================================================
Do something even longer ---------------------------------------------- 20.03s
Do something long ----------------------------------------------------- 10.02s
But what if you want to know how long one particular task was running and change flow of running tasks in playbook depending on this.
One way could be provide duration from module you’re running. If this is your custom module, it should be possible and not very hard.
To achieve this with any module, I think the easiest approach would be to register task data and calculate duration based on stop-start
timestamps, example:
---
- gather_facts: false
hosts: all
tasks:
- name: Do something long
ansible.builtin.pause:
seconds: 30
register: this
- set_fact:
duration: "{{ (this.stop|to_datetime('%Y-%m-%d %H:%M:%S.%f') - this.start|to_datetime('%Y-%m-%d %H:%M:%S.%f')).total_seconds() }}"
- debug:
var: duration
PLAY [all] ****************************************************************************************************************************************
TASK [Do something long] **************************************************************************************************************************
Sunday 05 January 2025 14:36:33 +0200 (0:00:00.007) 0:00:00.007 ********
Pausing for 30 seconds
(ctrl+C then 'C' = continue early, ctrl+C then 'A' = abort)
ok: [localhost]
TASK [set_fact] ***********************************************************************************************************************************
Sunday 05 January 2025 14:37:03 +0200 (0:00:30.031) 0:00:30.039 ********
ok: [localhost]
TASK [debug] **************************************************************************************************************************************
Sunday 05 January 2025 14:37:03 +0200 (0:00:00.035) 0:00:30.075 ********
ok: [localhost] => {
"duration": "30.005181"
}
PLAY RECAP ****************************************************************************************************************************************
localhost : ok=3 changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0
Sunday 05 January 2025 14:37:03 +0200 (0:00:00.013) 0:00:30.088 ********
===============================================================================
Do something long ------------------------------------------------------------------------------------------------------------------------- 30.03s
set_fact ----------------------------------------------------------------------------------------------------------------------------------- 0.04s
debug -------------------------------------------------------------------------------------------------------------------------------------- 0.01s
And then based on this duration variable, you can decide which tasks/roles to run.
P.S. Another option might be this approach from SO, when timestamps are registered before and after executed command(s).