Assess resource consumption with Ansible callback plugins

You can use Ansible callback plugins to get detailed information about your playbooks' metrics and machine resource consumption. Having this knowledge and the associated tools can be very useful for troubleshooting and getting a deeper understanding of Ansible plugins.

My previous article defines the environment and necessary components, and this article covers playbook execution tests using the callback plugins.

Understanding Ansible callback plugins

What are Ansible callback plugins? According to the documentation:

Callback plugins enable adding new behaviors to Ansible when responding to events. By default, callback plugins control most of the output you see when running the command line programs but can also be used to add additional output, integrate with other tools, and marshall the events to a storage backend

Fancy, right?

You can get more information about which callback plugins are available by running the ansible-doc -t callback -l command:

$ ansible-doc -t callback -l

[...]
cgroup_memory_recap  Profiles maximum memory usage of tasks and full execution using cgroups
cgroup_perf_recap    Profiles system activity of tasks and full execution using cgroups
[...]

The official documentation explains these two plugins, which are the focus of this article:

• cgroup_memory_recap: This is an Ansible callback plugin that profiles maximum memory usage of Ansible and individual tasks and displays a recap at the end using cgroups.
• cgroup_perf_recap: This is an Ansible callback plugin that utilizes cgroups to profile system activity of Ansible and individual tasks and display a recap at the end of the playbook execution.

Run the following command to display useful information about the acceptable parameters for each plugin. In this article, servera is your workstation, and serverb is a host  maintained with Ansible.

[servera]$ ansible-doc --type callback cgroup_memory_recap

[...]
= cur_mem_file
        Path to `memory.usage_in_bytes' file. Example `/sys/fs/cgroup/memory/ansible_profile/memory.usage_in_bytes'
[...]
= max_mem_file
        Path to cgroups `memory.max_usage_in_bytes' file. Example
        `/sys/fs/cgroup/memory/ansible_profile/memory.max_usage_in_bytes'
[...]
NOTES:
      * Requires ansible to be run from within a cgroup, such as with `cgexec -g memory:ansible_profile ansible-
        playbook ...'
      * This cgroup should only be used by ansible to get accurate results
      * To create the cgroup, first use a command such as `sudo cgcreate -a ec2-user:ec2-user -t
        ec2-user:ec2-user -g memory:ansible_profile'

REQUIREMENTS:  whitelist in configuration, cgroups
[...]

[servera]$ ansible-doc -t callback cgroup_perf_recap

[...]
= control_group
        Name of cgroups control group
[...]
NOTES:
      * Requires ansible to be run from within a cgroup, such as with `cgexec -g
        cpuacct,memory,pids:ansible_profile ansible-playbook ...'
      * This cgroup should only be used by ansible to get accurate results
      * To create the cgroup, first use a command such as `sudo cgcreate -a ec2-user:ec2-user -t
        ec2-user:ec2-user -g cpuacct,memory,pids:ansible_profile'

REQUIREMENTS:  whitelist in configuration, cgroups

Since both plugins require cgroups, install the libcgroup-tools package, which provides a userspace interface and management to this kernel feature:

[servera]$ sudo dnf install -y libcgroup-tools
[...]
Installed:
  libcgroup-0.41-19.el8.x86_64
  libcgroup-tools-0.41-19.el8.x86_64

Using callback plugins

To use these plugins during playbook execution, make some adjustments in the ansible.cfg file to define the callback_whitelist and the necessary parameters for both of them. Here is what the configuration file looks like after these adjustments:

[servera]$ cat ansible.cfg

[defaults]
inventory=hosts
remote_user=alexon
callback_whitelist=timer, profile_tasks, profile_roles, cgroup_perf_recap, cgroup_memory_recap

[callback_cgroup_perf_recap]
control_group=ansible_profile

[callback_cgroupmemrecap]
cur_mem_file = /sys/fs/cgroup/memory/ansible_profile/memory.usage_in_bytes
max_mem_file = /sys/fs/cgroup/memory/ansible_profile/memory.max_usage_in_bytes

[privilege_escalation]
become=True
become_method=sudo
become_user=root
become_ask_pass=False

Now almost everything is in place. To run the playbook and get per-Ansible-task CPU and memory usage statistics, first create a cgroup to run the playbook from, and then specify the controllers for the control group, as follows:

[servera]$ sudo cgcreate \
-a alexon:alexon \
-t alexon:alexon \
-g cpuacct,memory,pids:ansible_profile

Finally, the most awaited part has arrived! To activate the callback plugins during the playbook execution to get statistics, the playbooks need to run from inside the group. Recall that you created the deploy-webserver.yml and remove-webserver.yml playbooks in the first article.

[ Learn what's new in Red Hat Ansible Automation Platform 2. ]

First, activate the plugin with the deploy-webserver.yml playbook:

[servera]$ cgexec -g cpuacct,memory,pids:ansible_profile ansible-playbook deploy-webserver.yml

PLAY [Demo playbook to test callback plugin - Deployment] *******************************************************************************************

TASK [Gathering Facts] ******************************************************************************************************************************
Monday 27 September 2021  10:21:53 -0400 (0:00:00.026)       0:00:00.026 ******
Monday 27 September 2021  10:21:53 -0400 (0:00:00.026)       0:00:00.026 ******
ok: [serverb]

TASK [Install httpd package] ************************************************************************************************************************
Monday 27 September 2021  10:21:56 -0400 (0:00:02.838)       0:00:02.864 ******
Monday 27 September 2021  10:21:56 -0400 (0:00:02.838)       0:00:02.864 ******
changed: [serverb]

TASK [Start and enable httpd service] ***************************************************************************************************************
Monday 27 September 2021  10:22:19 -0400 (0:00:22.877)       0:00:25.742 ******
Monday 27 September 2021  10:22:19 -0400 (0:00:22.877)       0:00:25.742 ******
changed: [serverb]

TASK [Create a custom index.html file] **************************************************************************************************************
Monday 27 September 2021  10:22:21 -0400 (0:00:01.957)       0:00:27.700 ******
Monday 27 September 2021  10:22:21 -0400 (0:00:01.957)       0:00:27.700 ******
ok: [serverb]

PLAY RECAP ******************************************************************************************************************************************
serverb                    : ok=4    changed=2    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0   


CGROUP MEMORY RECAP *********************************************************************************************************************************
Execution Maximum: 83.96MB

Gathering Facts (5254009f-a4cd-6e20-f7d9-00000000000e): 78.97MB
Install httpd package (5254009f-a4cd-6e20-f7d9-000000000008): 80.52MB
Start and enable httpd service (5254009f-a4cd-6e20-f7d9-000000000009): 83.93MB
Create a custom index.html file (5254009f-a4cd-6e20-f7d9-00000000000a): 83.21MB

CGROUP PERF RECAP ***********************************************************************************************************************************
Memory Execution Maximum: 83.96MB
cpu Execution Maximum: 97.67%
pids Execution Maximum: 11.00

memory:
Gathering Facts (5254009f-a4cd-6e20-f7d9-00000000000e): 77.77MB
Install httpd package (5254009f-a4cd-6e20-f7d9-000000000008): 80.50MB
Start and enable httpd service (5254009f-a4cd-6e20-f7d9-000000000009): 82.68MB
Create a custom index.html file (5254009f-a4cd-6e20-f7d9-00000000000a): 82.37MB

cpu:
Gathering Facts (5254009f-a4cd-6e20-f7d9-00000000000e): 79.50%
Install httpd package (5254009f-a4cd-6e20-f7d9-000000000008): 81.02%
Start and enable httpd service (5254009f-a4cd-6e20-f7d9-000000000009): 97.67%
Create a custom index.html file (5254009f-a4cd-6e20-f7d9-00000000000a): 76.24%

pids:
Gathering Facts (5254009f-a4cd-6e20-f7d9-00000000000e): 9.00
Install httpd package (5254009f-a4cd-6e20-f7d9-000000000008): 10.00
Start and enable httpd service (5254009f-a4cd-6e20-f7d9-000000000009): 10.00
Create a custom index.html file (5254009f-a4cd-6e20-f7d9-00000000000a): 11.00

Monday 27 September 2021  10:22:22 -0400 (0:00:01.268)       0:00:28.969 ******
===============================================================================
dnf -------------------------------------------------------------------- 22.88s
gather_facts ------------------------------------------------------------ 2.84s
service ----------------------------------------------------------------- 1.96s
copy -------------------------------------------------------------------- 1.27s
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
total ------------------------------------------------------------------ 28.94s
Monday 27 September 2021  10:22:22 -0400 (0:00:01.268)       0:00:28.968 ******
===============================================================================
Install httpd package ----------------------------------------------------------------------------------------------------------------------- 22.88s
Gathering Facts ------------------------------------------------------------------------------------------------------------------------------ 2.84s
Start and enable httpd service --------------------------------------------------------------------------------------------------------------- 1.96s
Create a custom index.html file -------------------------------------------------------------------------------------------------------------- 1.27s
Playbook run took 0 days, 0 hours, 0 minutes, 28 seconds

Look how much information is displayed. You can spot how many resources were consumed by each task and how much time each one took. It's amazing! To make sure the web server is running smoothly, use curl to see the main page:

[servera]$ curl -s http://serverb/index.html

Enable SysAdmin Demo:
Ansible Profiling with Callback Plugin
Custom Web Page

It's alive (pun intended)! Next, get statistics for removing the httpd service from the target machine by running the remove-webserver.yml playbook:

[servera]$ cgexec -g cpuacct,memory,pids:ansible_profile ansible-playbook remove-webserver.yml

PLAY [Demo playbook to test callback plugin - Remove] ***********************************************************************************************

TASK [Gathering Facts] ******************************************************************************************************************************
Monday 27 September 2021  10:25:16 -0400 (0:00:00.025)       0:00:00.025 ******
Monday 27 September 2021  10:25:16 -0400 (0:00:00.024)       0:00:00.024 ******
ok: [serverb]

TASK [Stop and disable httpd service] ***************************************************************************************************************
Monday 27 September 2021  10:25:17 -0400 (0:00:01.669)       0:00:01.695 ******
Monday 27 September 2021  10:25:17 -0400 (0:00:01.670)       0:00:01.694 ******
changed: [serverb]

TASK [Remove httpd package] ************************************************************************************************************************
Monday 27 September 2021  10:25:19 -0400 (0:00:02.093)       0:00:03.788 ******
Monday 27 September 2021  10:25:19 -0400 (0:00:02.093)       0:00:03.787 ******
changed: [serverb]

PLAY RECAP ******************************************************************************************************************************************
serverb                    : ok=3    changed=2    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0   


CGROUP MEMORY RECAP *********************************************************************************************************************************
Execution Maximum: 82.04MB

Gathering Facts (5254009f-a4cd-05bf-a1a8-00000000000d): 78.05MB
Stop and disable httpd service (5254009f-a4cd-05bf-a1a8-000000000008): 81.98MB
Remove httpd package (5254009f-a4cd-05bf-a1a8-000000000009): 80.35MB

CGROUP PERF RECAP ***********************************************************************************************************************************
Memory Execution Maximum: 82.04MB
cpu Execution Maximum: 87.04%
pids Execution Maximum: 10.00

memory:
Gathering Facts (5254009f-a4cd-05bf-a1a8-00000000000d): 76.88MB
Stop and disable httpd service (5254009f-a4cd-05bf-a1a8-000000000008): 80.91MB
Remove httpd package (5254009f-a4cd-05bf-a1a8-000000000009): 80.20MB

cpu:
Gathering Facts (5254009f-a4cd-05bf-a1a8-00000000000d): 87.04%
Stop and disable httpd service (5254009f-a4cd-05bf-a1a8-000000000008): 82.20%
Remove httpd package (5254009f-a4cd-05bf-a1a8-000000000009): 80.81%

pids:
Gathering Facts (5254009f-a4cd-05bf-a1a8-00000000000d): 9.00
Stop and disable httpd service (5254009f-a4cd-05bf-a1a8-000000000008): 10.00
Remove httpd package (5254009f-a4cd-05bf-a1a8-000000000009): 10.00

Monday 27 September 2021  10:25:35 -0400 (0:00:15.336)       0:00:19.124 ******
===============================================================================
dnf -------------------------------------------------------------------- 15.34s
service ----------------------------------------------------------------- 2.09s
gather_facts ------------------------------------------------------------ 1.67s
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
total ------------------------------------------------------------------ 19.10s
Monday 27 September 2021  10:25:35 -0400 (0:00:15.336)       0:00:19.124 ******
===============================================================================
Remove httpd package ----------------------------------------------------------------------------------------------------------------------- 15.34s
Stop and disable httpd service --------------------------------------------------------------------------------------------------------------- 2.09s
Gathering Facts ------------------------------------------------------------------------------------------------------------------------------ 1.67s
Playbook run took 0 days, 0 hours, 0 minutes, 19 seconds

To confirm the playbook executed successfully, check that the web server is no longer alive:

[servera]$ curl -s http://serverb/index.html

[servera]$ curl -v http://serverb/index.html

*   Trying 192.168.1.14...
* TCP_NODELAY set
* connect to 192.168.1.14 port 80 failed: Connection refused
* Failed to connect to serverb port 80: Connection refused
* Closing connection 0
curl: (7) Failed to connect to serverb port 80: Connection refused

And just like that, you get detailed information while running Ansible playbooks, generating more productive inputs for your daily tasks. And the coolest thing is that you can also explore other available callback plugins that can be used with Ansible Tower. That's a subject for another article.

Wrapping up

The default outputs from Ansible ad-hoc commands and playbooks are intended to be lean and clean. However, when you need metrics and statistics after execution, callback plugins come in handy to drill down into this information to aid in troubleshooting.

These articles offer a basic demonstration of how Ansible callback plugins work. Part one establishes the environment and necessary utilities. Part two covers using two of these plugins to profile system activity and maximum memory usage by tasks and full execution using cgroups. Now that you know how to do it, put it to good use!