From 150def6015a6c583375aabdf2ea7980239142773 Mon Sep 17 00:00:00 2001 From: Matt Davis <6775756+nitzmahone@users.noreply.github.com> Date: Wed, 27 Sep 2023 14:04:07 -0700 Subject: [PATCH] fix various Jinja plugin caching issues (#79781) (#81644) * fix various Jinja plugin caching issues * consolidate the wrapper plugin cache * remove redundant cache in J2 filter/test interceptor * intra-template loader bypass * fix early exits swallowing some exception detail * misc comment cleanup (cherry picked from commit dd79c49a4de3a6dd5bd9d31503bd7846475e8e57) --- .../fragments/jinja_plugin_cache_cleanup.yml | 2 + lib/ansible/plugins/loader.py | 152 ++++++++---------- lib/ansible/template/__init__.py | 13 +- .../integration/targets/collections/posix.yml | 4 +- 4 files changed, 77 insertions(+), 94 deletions(-) create mode 100644 changelogs/fragments/jinja_plugin_cache_cleanup.yml diff --git a/changelogs/fragments/jinja_plugin_cache_cleanup.yml b/changelogs/fragments/jinja_plugin_cache_cleanup.yml new file mode 100644 index 00000000000..32932f04e0d --- /dev/null +++ b/changelogs/fragments/jinja_plugin_cache_cleanup.yml @@ -0,0 +1,2 @@ +bugfixes: + - PluginLoader - fix Jinja plugin performance issues (https://github.com/ansible/ansible/issues/79652) \ No newline at end of file diff --git a/lib/ansible/plugins/loader.py b/lib/ansible/plugins/loader.py index 845fdcd0e38..8b7fbfce823 100644 --- a/lib/ansible/plugins/loader.py +++ b/lib/ansible/plugins/loader.py @@ -17,6 +17,10 @@ import warnings from collections import defaultdict, namedtuple from traceback import format_exc + +from .filter import AnsibleJinja2Filter +from .test import AnsibleJinja2Test + from ansible import __version__ as ansible_version from ansible import constants as C from ansible.errors import AnsibleError, AnsiblePluginCircularRedirect, AnsiblePluginRemovedError, AnsibleCollectionUnsupportedVersionError @@ -1065,28 +1069,17 @@ class Jinja2Loader(PluginLoader): We need to do a few things differently in the base class because of file == plugin assumptions and dedupe logic. """ - def __init__(self, class_name, package, config, subdir, aliases=None, required_base_class=None): - + def __init__(self, class_name, package, config, subdir, plugin_wrapper_type, aliases=None, required_base_class=None): super(Jinja2Loader, self).__init__(class_name, package, config, subdir, aliases=aliases, required_base_class=required_base_class) - self._loaded_j2_file_maps = [] + self._plugin_wrapper_type = plugin_wrapper_type + self._cached_non_collection_wrappers = {} def _clear_caches(self): super(Jinja2Loader, self)._clear_caches() - self._loaded_j2_file_maps = [] + self._cached_non_collection_wrappers = {} def find_plugin(self, name, mod_type='', ignore_deprecated=False, check_aliases=False, collection_list=None): - - # TODO: handle collection plugin find, see 'get_with_context' - # this can really 'find plugin file' - plugin = super(Jinja2Loader, self).find_plugin(name, mod_type=mod_type, ignore_deprecated=ignore_deprecated, check_aliases=check_aliases, - collection_list=collection_list) - - # if not found, try loading all non collection plugins and see if this in there - if not plugin: - all_plugins = self.all() - plugin = all_plugins.get(name, None) - - return plugin + raise NotImplementedError('find_plugin is not supported on Jinja2Loader') @property def method_map_name(self): @@ -1120,8 +1113,7 @@ class Jinja2Loader(PluginLoader): for func_name, func in plugin_map: fq_name = '.'.join((collection, func_name)) full = '.'.join((full_name, func_name)) - pclass = self._load_jinja2_class() - plugin = pclass(func) + plugin = self._plugin_wrapper_type(func) if plugin in plugins: continue self._update_object(plugin, full, plugin_path, resolved=fq_name) @@ -1129,27 +1121,28 @@ class Jinja2Loader(PluginLoader): return plugins + # FUTURE: now that the resulting plugins are closer, refactor base class method with some extra + # hooks so we can avoid all the duplicated plugin metadata logic, and also cache the collection results properly here def get_with_context(self, name, *args, **kwargs): - - # found_in_cache = True - class_only = kwargs.pop('class_only', False) # just pop it, dont want to pass through - collection_list = kwargs.pop('collection_list', None) + # pop N/A kwargs to avoid passthrough to parent methods + kwargs.pop('class_only', False) + kwargs.pop('collection_list', None) context = PluginLoadContext() # avoid collection path for legacy name = name.removeprefix('ansible.legacy.') - if '.' not in name: - # Filter/tests must always be FQCN except builtin and legacy - for known_plugin in self.all(*args, **kwargs): - if known_plugin.matches_name([name]): - context.resolved = True - context.plugin_resolved_name = name - context.plugin_resolved_path = known_plugin._original_path - context.plugin_resolved_collection = 'ansible.builtin' if known_plugin.ansible_name.startswith('ansible.builtin.') else '' - context._resolved_fqcn = known_plugin.ansible_name - return get_with_context_result(known_plugin, context) + self._ensure_non_collection_wrappers(*args, **kwargs) + + # check for stuff loaded via legacy/builtin paths first + if known_plugin := self._cached_non_collection_wrappers.get(name): + context.resolved = True + context.plugin_resolved_name = name + context.plugin_resolved_path = known_plugin._original_path + context.plugin_resolved_collection = 'ansible.builtin' if known_plugin.ansible_name.startswith('ansible.builtin.') else '' + context._resolved_fqcn = known_plugin.ansible_name + return get_with_context_result(known_plugin, context) plugin = None key, leaf_key = get_fqcr_and_name(name) @@ -1235,14 +1228,10 @@ class Jinja2Loader(PluginLoader): # use 'parent' loader class to find files, but cannot return this as it can contain # multiple plugins per file plugin_impl = super(Jinja2Loader, self).get_with_context(module_name, *args, **kwargs) - except Exception as e: - raise KeyError(to_native(e)) - - try: method_map = getattr(plugin_impl.object, self.method_map_name) plugin_map = method_map().items() except Exception as e: - display.warning("Skipping %s plugins in '%s' as it seems to be invalid: %r" % (self.type, to_text(plugin_impl.object._original_path), e)) + display.warning(f"Skipping {self.type} plugins in {module_name}'; an error occurred while loading: {e}") continue for func_name, func in plugin_map: @@ -1251,11 +1240,11 @@ class Jinja2Loader(PluginLoader): # TODO: load anyways into CACHE so we only match each at end of loop # the files themseves should already be cached by base class caching of modules(python) if key in (func_name, fq_name): - pclass = self._load_jinja2_class() - plugin = pclass(func) + plugin = self._plugin_wrapper_type(func) if plugin: context = plugin_impl.plugin_load_context self._update_object(plugin, src_name, plugin_impl.object._original_path, resolved=fq_name) + # FIXME: once we start caching these results, we'll be missing functions that would have loaded later break # go to next file as it can override if dupe (dont break both loops) except AnsiblePluginRemovedError as apre: @@ -1270,8 +1259,7 @@ class Jinja2Loader(PluginLoader): return get_with_context_result(plugin, context) def all(self, *args, **kwargs): - - # inputs, we ignore 'dedupe' we always do, used in base class to find files for this one + kwargs.pop('_dedupe', None) path_only = kwargs.pop('path_only', False) class_only = kwargs.pop('class_only', False) # basically ignored for test/filters since they are functions @@ -1279,9 +1267,19 @@ class Jinja2Loader(PluginLoader): if path_only and class_only: raise AnsibleError('Do not set both path_only and class_only when calling PluginLoader.all()') - found = set() + self._ensure_non_collection_wrappers(*args, **kwargs) + if path_only: + yield from (w._original_path for w in self._cached_non_collection_wrappers.values()) + else: + yield from (w for w in self._cached_non_collection_wrappers.values()) + + def _ensure_non_collection_wrappers(self, *args, **kwargs): + if self._cached_non_collection_wrappers: + return + # get plugins from files in configured paths (multiple in each) - for p_map in self._j2_all_file_maps(*args, **kwargs): + for p_map in super(Jinja2Loader, self).all(*args, **kwargs): + is_builtin = p_map.ansible_name.startswith('ansible.builtin.') # p_map is really object from file with class that holds multiple plugins plugins_list = getattr(p_map, self.method_map_name) @@ -1292,57 +1290,35 @@ class Jinja2Loader(PluginLoader): continue for plugin_name in plugins.keys(): - if plugin_name in _PLUGIN_FILTERS[self.package]: - display.debug("%s skipped due to a defined plugin filter" % plugin_name) + if '.' in plugin_name: + display.debug(f'{plugin_name} skipped in {p_map._original_path}; Jinja plugin short names may not contain "."') continue - if plugin_name in found: - display.debug("%s skipped as duplicate" % plugin_name) + if plugin_name in _PLUGIN_FILTERS[self.package]: + display.debug("%s skipped due to a defined plugin filter" % plugin_name) continue - if path_only: - result = p_map._original_path - else: - # loader class is for the file with multiple plugins, but each plugin now has it's own class - pclass = self._load_jinja2_class() - result = pclass(plugins[plugin_name]) # if bad plugin, let exception rise - found.add(plugin_name) - fqcn = plugin_name - collection = '.'.join(p_map.ansible_name.split('.')[:2]) if p_map.ansible_name.count('.') >= 2 else '' - if not plugin_name.startswith(collection): - fqcn = f"{collection}.{plugin_name}" - - self._update_object(result, plugin_name, p_map._original_path, resolved=fqcn) - yield result - - def _load_jinja2_class(self): - """ override the normal method of plugin classname as these are used in the generic funciton - to access the 'multimap' of filter/tests to function, this is a 'singular' plugin for - each entry. - """ - class_name = 'AnsibleJinja2%s' % get_plugin_class(self.class_name).capitalize() - module = __import__(self.package, fromlist=[class_name]) - - return getattr(module, class_name) + # the plugin class returned by the loader may host multiple Jinja plugins, but we wrap each plugin in + # its own surrogate wrapper instance here to ease the bookkeeping... + wrapper = self._plugin_wrapper_type(plugins[plugin_name]) + fqcn = plugin_name + collection = '.'.join(p_map.ansible_name.split('.')[:2]) if p_map.ansible_name.count('.') >= 2 else '' + if not plugin_name.startswith(collection): + fqcn = f"{collection}.{plugin_name}" - def _j2_all_file_maps(self, *args, **kwargs): - """ - * Unlike other plugin types, file != plugin, a file can contain multiple plugins (of same type). - This is why we do not deduplicate ansible file names at this point, we mostly care about - the names of the actual jinja2 plugins which are inside of our files. - * This method will NOT fetch collection plugin files, only those that would be expected under 'ansible.builtin/legacy'. - """ - # populate cache if needed - if not self._loaded_j2_file_maps: + self._update_object(wrapper, plugin_name, p_map._original_path, resolved=fqcn) - # We don't deduplicate ansible file names. - # Instead, calling code deduplicates jinja2 plugin names when loading each file. - kwargs['_dedupe'] = False + target_names = {plugin_name, fqcn} + if is_builtin: + target_names.add(f'ansible.builtin.{plugin_name}') - # To match correct precedence, call base class' all() to get a list of files, - self._loaded_j2_file_maps = list(super(Jinja2Loader, self).all(*args, **kwargs)) + for target_name in target_names: + if existing_plugin := self._cached_non_collection_wrappers.get(target_name): + display.debug(f'Jinja plugin {target_name} from {p_map._original_path} skipped; ' + f'shadowed by plugin from {existing_plugin._original_path})') + continue - return self._loaded_j2_file_maps + self._cached_non_collection_wrappers[target_name] = wrapper def get_fqcr_and_name(resource, collection='ansible.builtin'): @@ -1551,13 +1527,15 @@ filter_loader = Jinja2Loader( 'ansible.plugins.filter', C.DEFAULT_FILTER_PLUGIN_PATH, 'filter_plugins', + AnsibleJinja2Filter ) test_loader = Jinja2Loader( 'TestModule', 'ansible.plugins.test', C.DEFAULT_TEST_PLUGIN_PATH, - 'test_plugins' + 'test_plugins', + AnsibleJinja2Test ) strategy_loader = PluginLoader( diff --git a/lib/ansible/template/__init__.py b/lib/ansible/template/__init__.py index 17bee104893..baa85ed7934 100644 --- a/lib/ansible/template/__init__.py +++ b/lib/ansible/template/__init__.py @@ -412,11 +412,11 @@ class JinjaPluginIntercept(MutableMapping): self._pluginloader = pluginloader - # cache of resolved plugins + # Jinja environment's mapping of known names (initially just J2 builtins) self._delegatee = delegatee - # track loaded plugins here as cache above includes 'jinja2' filters but ours should override - self._loaded_builtins = set() + # our names take precedence over Jinja's, but let things we've tried to resolve skip the pluginloader + self._seen_it = set() def __getitem__(self, key): @@ -424,7 +424,10 @@ class JinjaPluginIntercept(MutableMapping): raise ValueError('key must be a string, got %s instead' % type(key)) original_exc = None - if key not in self._loaded_builtins: + if key not in self._seen_it: + # this looks too early to set this- it isn't. Setting it here keeps requests for Jinja builtins from + # going through the pluginloader more than once, which is extremely slow for something that won't ever succeed. + self._seen_it.add(key) plugin = None try: plugin = self._pluginloader.get(key) @@ -438,12 +441,12 @@ class JinjaPluginIntercept(MutableMapping): if plugin: # set in filter cache and avoid expensive plugin load self._delegatee[key] = plugin.j2_function - self._loaded_builtins.add(key) # raise template syntax error if we could not find ours or jinja2 one try: func = self._delegatee[key] except KeyError as e: + self._seen_it.remove(key) raise TemplateSyntaxError('Could not load "%s": %s' % (key, to_native(original_exc or e)), 0) # if i do have func and it is a filter, it nees wrapping diff --git a/test/integration/targets/collections/posix.yml b/test/integration/targets/collections/posix.yml index 903fb4ff580..4db20003f22 100644 --- a/test/integration/targets/collections/posix.yml +++ b/test/integration/targets/collections/posix.yml @@ -151,8 +151,8 @@ - assert: that: - - | - 'This is a broken filter plugin.' in result.msg + # FUTURE: ensure that the warning was also issued with the actual failure details + - result is failed - debug: msg: "{{ 'foo'|missing.collection.filter }}"