Improved Jinja plugin caching breaks loading multiple custom filter plugins with same name

[ppmathis]

Summary

Due to the recent issues with the default AWX execution environment with Ansible Galaxy collections (see ansible/awx#14495 (comment)), a new AWX EE has been shipped which contains Ansible Core v2.15.5rc1, to which we also upgraded.

This unfortunately ended up breaking various playbooks on our side, which made use of custom Jinja filters stored within individual role directories. As an example, here is the error message for a dummy role which uses an existing filter named hello:

fatal: [localhost]: FAILED! => {
    "msg": "template error while templating string: Could not load \"hello\": 'hello'. String: {{ \"Ansible\" | hello(\"!\") }}. Could not load \"hello\": 'hello'"
}

After a bit of digging and testing various constellations, I noticed that the issue has been introduced between v2.15.4 and v2.15.5rc1, specifically by this PR: #79781

The issue only appears under the following conditions:

• At least two roles exist, each with their own filter_plugins directory
• At least two roles use the same name for the Python module which implements the custom filter(s), e.g. custom.py
• At least one role with a custom filter plugin that has the same name is being executed BEFORE the role which uses a custom filter is executed

This will then result in an error message when running the second role which states that the filter could not be loaded. As a workaround, the issue can be prevented by giving each filter plugin module its unique filename (unique across all roles), e.g. custom1.py and custom2.py

Last but not least, I also reproduced this issue when running the latest develop branch and verified that reverting the merge commit for #79781 fixes the issue, so it seems like this updated cache routine ended up breaking this functionality.

I created a reproducer repository on GitHub for further reference.

Issue Type

Bug Report

Component Name

loader

Ansible Version

$ ansible --version
ansible [core 2.15.5rc1]
  config file = None
  configured module search path = ['/runner/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/local/lib/python3.9/site-packages/ansible
  ansible collection location = /runner/.ansible/collections:/usr/share/ansible/collections
  executable location = /usr/local/bin/ansible
  python version = 3.9.17 (main, Aug  9 2023, 00:00:00) [GCC 11.4.1 20230605 (Red Hat 11.4.1-2)] (/usr/bin/python3)
  jinja version = 3.1.2
  libyaml = True

Configuration

# if using a version older than ansible-core 2.12 you should omit the '-t all'
$ ansible-config dump --only-changed -t all
CONFIG_FILE() = None

OS / Environment

Version information and configuration dump based on quay.io/ansible/awx-ee:latest with digest 921344c370b8844de83f693773853fab2f754ae738f6dee4ee5e101d8ee760eb (ships v2.15.5rc1 as of today), but issue was also reproduced with current develop branch from Ansible Core.

Other versions like OS etc. do not really matter, it's an issue within the plugin loader of Ansible Core and can be easily reproduced anywhere, including blank Python container images.

Steps to Reproduce

I created a reproducer repository at https://github.com/ppmathis/ansible-plugin-issue which has a minimal example for triggering this issue with v2.15.5rc1. Alternatively, you can reproduce this structure yourself:

1. Create a role first-role with a custom filter plugin module named custom.py and write any custom filter. Add a task file which uses this filter somehow. In my reproducer repository, I called the filter goodbye.
2. Create a second role second-role with a custom filter plugin module which is also named custom.py and write another filter. Add a task file which uses this filter somehow. In my reproducer repository, I called the filter hello.
3. Create a new playbook which includes both roles.
4. Run this playbook using ansible-playbook with no specific flags or options.

Expected Results

Both roles should be able to use the custom filters without any issue, even when the respective Python modules have the same filename.

Actual Results

ansible-playbook [core 2.15.5rc1]
  config file = None
  configured module search path = ['/root/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /app/venv/lib/python3.12/site-packages/ansible
  ansible collection location = /root/.ansible/collections:/usr/share/ansible/collections
  executable location = /app/venv/bin/ansible-playbook
  python version = 3.12.0 (main, Oct  3 2023, 01:48:15) [GCC 12.2.0] (/app/venv/bin/python)
  jinja version = 3.1.2
  libyaml = True
No config file found; using defaults
setting up inventory plugins
Loading collection ansible.builtin from 
host_list declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Skipping due to inventory source not existing or not being readable by the current user
script declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
auto declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Skipping due to inventory source not existing or not being readable by the current user
yaml declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Skipping due to inventory source not existing or not being readable by the current user
ini declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Skipping due to inventory source not existing or not being readable by the current user
toml declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
[WARNING]: No inventory was parsed, only implicit localhost is available
[WARNING]: provided hosts list is empty, only localhost is available. Note that the implicit localhost does not match 'all'
Loading callback plugin default of type stdout, v2.0 from /app/venv/lib/python3.12/site-packages/ansible/plugins/callback/default.py
Skipping callback 'default', as we already have a stdout callback.
Skipping callback 'minimal', as we already have a stdout callback.
Skipping callback 'oneline', as we already have a stdout callback.

PLAYBOOK: site.yml ***************************************************************************************************************************************************************************************************************************************************
Positional arguments: site.yml
verbosity: 4
connection: smart
timeout: 10
become_method: sudo
tags: ('all',)
inventory: ('/etc/ansible/hosts',)
forks: 5
1 plays in site.yml

PLAY [localhost] *****************************************************************************************************************************************************************************************************************************************************

TASK [Gathering Facts] ***********************************************************************************************************************************************************************************************************************************************
task path: /app/site.yml:2
<127.0.0.1> ESTABLISH LOCAL CONNECTION FOR USER: root
<127.0.0.1> EXEC /bin/sh -c 'echo ~root && sleep 0'
<127.0.0.1> EXEC /bin/sh -c '( umask 77 && mkdir -p "` echo /root/.ansible/tmp `"&& mkdir "` echo /root/.ansible/tmp/ansible-tmp-1696435231.9647672-10-91811106198726 `" && echo ansible-tmp-1696435231.9647672-10-91811106198726="` echo /root/.ansible/tmp/ansible-tmp-1696435231.9647672-10-91811106198726 `" ) && sleep 0'
Using module file /app/venv/lib/python3.12/site-packages/ansible/modules/setup.py
<127.0.0.1> PUT /root/.ansible/tmp/ansible-local-1gjwhoirf/tmprgv1l_0w TO /root/.ansible/tmp/ansible-tmp-1696435231.9647672-10-91811106198726/AnsiballZ_setup.py
<127.0.0.1> EXEC /bin/sh -c 'chmod u+x /root/.ansible/tmp/ansible-tmp-1696435231.9647672-10-91811106198726/ /root/.ansible/tmp/ansible-tmp-1696435231.9647672-10-91811106198726/AnsiballZ_setup.py && sleep 0'
<127.0.0.1> EXEC /bin/sh -c '/app/venv/bin/python /root/.ansible/tmp/ansible-tmp-1696435231.9647672-10-91811106198726/AnsiballZ_setup.py && sleep 0'
<127.0.0.1> EXEC /bin/sh -c 'rm -f -r /root/.ansible/tmp/ansible-tmp-1696435231.9647672-10-91811106198726/ > /dev/null 2>&1 && sleep 0'
ok: [localhost]

TASK [first-role : ansible.builtin.debug] ****************************************************************************************************************************************************************************************************************************
task path: /app/roles/first-role/tasks/main.yml:2
ok: [localhost] => {
    "msg": "Goodbye Ansible!"
}

TASK [second-role : ansible.builtin.debug] ***************************************************************************************************************************************************************************************************************************
task path: /app/roles/second-role/tasks/main.yml:2
fatal: [localhost]: FAILED! => {
    "msg": "template error while templating string: Could not load \"hello\": 'hello'. String: {{ \"Ansible\" | hello(\"!\") }}. Could not load \"hello\": 'hello'"
}

PLAY RECAP ***********************************************************************************************************************************************************************************************************************************************************
localhost                  : ok=2    changed=0    unreachable=0    failed=1    skipped=0    rescued=0    ignored=0

Code of Conduct

• I agree to follow the Ansible Code of Conduct

[ansibot]

Files identified in the description:

None

If these files are incorrect, please update the component name section of the description or use the component bot command.

[sivel]

I've tracked this down a bit. In _j2_all_file_maps we used to set kwargs['_dedupe'] = False. That function no longer exists.

I think we need to do this to restore the functionality:

diff --git a/lib/ansible/plugins/loader.py b/lib/ansible/plugins/loader.py
index 9e8213518e..c6dd849d4f 100644
--- a/lib/ansible/plugins/loader.py
+++ b/lib/ansible/plugins/loader.py
@@ -1308,7 +1308,7 @@ class Jinja2Loader(PluginLoader):
             return

         # get plugins from files in configured paths (multiple in each)
-        for p_map in super(Jinja2Loader, self).all(*args, **kwargs):
+        for p_map in super(Jinja2Loader, self).all(*args, _dedupe=False, **kwargs):
             is_builtin = p_map.ansible_name.startswith('ansible.builtin.')

             # p_map is really object from file with class that holds multiple plugins

Otherwise, we need to stop deduping on basename and instead dedupe on full path.

[bcoca]

@ppmathis please confirm that the linked PR corrects the issue

[ppmathis]

@bcoca Just successfully verified that your linked PR does indeed fix the issue, both for my reproducer and the actual project where I've stumbled across this issue. Thanks a lot! 👍