Plugin reload limitations (#13007)

* Improve auto-reload of plugin

Ensure entire module is reloaded

* Add regression tests

* Updated docs

* Detect plugin reload loop - and report error

src/backend/InvenTree/plugin/registry.py

@@ -87,6 +87,10 @@ class PluginsRegistry:
 
     DEFAULT_MIXIN_ORDER = [SettingsMixin, ScheduleMixin, AppMixin, UrlsMixin]
 
+    # Number of consecutive reloads which may fail to reproduce the same registry hash,
+    # before the mismatch is reported as an error (and reloading for that hash stops)
+    MAX_MISMATCH_RELOADS = 2
+
     # This list of plugins are *always* enabled, and are loaded by default
     # This is because they provide core functionality to the InvenTree system
     # Other 'builtin' plugins are automatically loaded, but can be disabled by the user
@@ -125,6 +129,11 @@ class PluginsRegistry:
         # Keep an internal hash of the plugin registry state
         self.registry_hash: Optional[str] = None
 
+        # Track a registry hash (published by another process) which this process
+        # could not reproduce on reload - used to detect a plugin reload loop
+        self.mismatch_hash: Optional[str] = None
+        self.mismatch_count: int = 0
+
         self.plugin_modules: list[InvenTreePlugin] = []  # Holds all discovered plugins
         self.mixin_modules: dict[str, Any] = {}  # Holds all discovered mixins
 
@@ -464,8 +473,9 @@ class PluginsRegistry:
         force_reload: bool = False,
         collect: bool = False,
         clear_errors: bool = False,
+        update_hash: bool = True,
         _internal: Optional[list] = None,
-    ):
+    ) -> bool:
         """Reload the plugin registry.
 
         This should be considered the single point of entry for loading plugins!
@@ -475,16 +485,20 @@ class PluginsRegistry:
             force_reload (bool, optional): Also reload base apps. Defaults to False.
             collect (bool, optional): Collect plugins before reloading. Defaults to False.
             clear_errors (bool, optional): Clear any previous loading errors. Defaults to False.
+            update_hash (bool, optional): Publish the resulting registry hash to the database. Defaults to True.
             _internal (list, optional): Internal apps to reload (used for testing). Defaults to None
+
+        Returns:
+            bool: True if the registry was reloaded, False if the reload was skipped or failed
         """
         # Do not reload when currently loading
         if self.is_loading:
             logger.debug('Skipping reload - plugin registry is currently loading')
-            return
+            return False
 
         if not self.loading_lock.acquire(blocking=False):
             logger.exception('Could not acquire lock for reload_plugins')
-            return
+            return False
 
         # Reset the loading error state
         if clear_errors:
@@ -519,7 +533,11 @@ class PluginsRegistry:
             self.plugins_loaded = True
             self._load_plugins(full_reload=full_reload, _internal=_internal)
 
-            self.update_plugin_hash()
+            if update_hash:
+                self.update_plugin_hash()
+            else:
+                self.registry_hash = self.calculate_plugin_hash()
+
             logger.info('Plugin Registry: Loaded %s plugins', len(self.plugins))
 
             # Ensure that each loaded plugin has a valid configuration object in the database; skip if setup is initializing
@@ -543,11 +561,14 @@ class PluginsRegistry:
         except Exception as e:
             logger.exception('Unexpected error during plugin reload: %s', e)
             log_error('reload_plugins', scope='plugins')
+            return False
 
         finally:
             # Ensure the lock is released always
             self.loading_lock.release()
 
+        return True
+
     def plugin_dirs(self) -> list[str]:
         """Construct a list of directories from where plugins can be loaded."""
         # Builtin plugins are *always* loaded
@@ -655,8 +676,14 @@ class PluginsRegistry:
             if (not settings.PLUGIN_TESTING) or (
                 settings.PLUGIN_TESTING and settings.PLUGIN_TESTING_SETUP
             ):
+                entries = list(get_entrypoints())
+
+                # Discard any previously imported plugin code, so that the
+                # current on-disk version is imported below
+                self._purge_plugin_modules(entries)
+
                 # Collect plugins from setup entry points
-                for entry in get_entrypoints():
+                for entry in entries:
                     logger.debug(
                         "Loading plugin '%s' from module '%s'", entry.name, entry.module
                     )
@@ -676,6 +703,47 @@ class PluginsRegistry:
 
         return collected_plugins
 
+    def _purge_plugin_modules(self, entries) -> None:
+        """Remove the modules of package plugins from sys.modules.
+
+        When a plugin package is updated on disk (e.g. via pip), this process
+        still holds the previously imported modules. Reloading only the module
+        which defines the plugin class is not sufficient, as the rest of the
+        package (e.g. the parent __init__.py, or any sibling modules) would
+        remain stale. Instead, the entire top-level package is discarded,
+        so that the next import loads the current code from disk.
+
+        This must happen in every process (web and background worker) on
+        reload, otherwise processes report different plugin versions and
+        the registry hash never settles.
+
+        Args:
+            entries: Plugin entry points to purge the packages for
+        """
+        base_dir = Path(settings.BASE_DIR).resolve()
+        packages = set()
+
+        for entry in entries:
+            if package := entry.module.split('.')[0]:
+                packages.add(package)
+
+        for package in packages:
+            # Never purge InvenTree's own modules
+            module = sys.modules.get(package)
+            module_file = getattr(module, '__file__', None)
+
+            if module_file and Path(module_file).resolve().is_relative_to(base_dir):
+                continue
+
+            for name in [
+                name
+                for name in list(sys.modules)
+                if name == package or name.startswith(f'{package}.')
+            ]:
+                del sys.modules[name]
+
+        importlib.invalidate_caches()
+
     def discover_mixins(self):
         """Discover all mixins from plugins and register them."""
         collected_mixins = {}
@@ -777,10 +845,6 @@ class PluginsRegistry:
 
         plugin.db = plg_db
 
-        # Check if this is a 'builtin' plugin
-        builtin = plg_db.is_builtin() if plg_db else plugin.check_is_builtin()
-        sample = plg_db.is_sample() if plg_db else plugin.check_is_sample()
-
         package_name = None
 
         # Extract plugin package name
@@ -811,29 +875,8 @@ class PluginsRegistry:
             # Initialize package - we can be sure that an admin has activated the plugin
             logger.debug('Loading plugin `%s`', plg_name)
 
-            # If this is a third-party plugin, reload the source module
-            # This is required to ensure that separate processes are using the same code
-            if not builtin and not sample:
-                plugin_name = plugin.__name__
-                module_name = plugin.__module__
-
-                if plugin_module := sys.modules.get(module_name):
-                    logger.debug('Reloading plugin `%s`', plg_name)
-                    # Reload the module
-                    try:
-                        importlib.reload(plugin_module)
-                        plugin = getattr(plugin_module, plugin_name)
-                    except ModuleNotFoundError:
-                        # No module found - try to import it directly
-                        try:
-                            raw_module = _load_source(
-                                module_name, plugin_module.__file__
-                            )
-                            plugin = getattr(raw_module, plugin_name)
-                        except Exception:
-                            pass
-                    except Exception:
-                        logger.exception('Failed to reload plugin `%s`', plg_name)
+            # Note: Package plugins are re-imported from disk when collected
+            # (see _purge_plugin_modules), so no module reload is required here
 
             try:
                 t_start = time.time()
@@ -1189,6 +1232,14 @@ class PluginsRegistry:
         if not reg_hash or reg_hash == self.registry_hash:
             return False
 
+        if (
+            reg_hash == self.mismatch_hash
+            and self.mismatch_count >= self.MAX_MISMATCH_RELOADS
+        ):
+            # This process has already failed to reproduce this registry state
+            # (and the error has been reported) - do not keep reloading
+            return False
+
         # A mismatch was observed - acquire a short-lived lease before reloading
         if not try_acquire_lease('_PLUGIN_REGISTRY_HASH'):
             return False
@@ -1204,11 +1255,89 @@ class PluginsRegistry:
                 return False
 
             logger.info('Plugin registry hash has changed - reloading')
-            self.reload_plugins(full_reload=True, force_reload=True, collect=True)
+
+            # Note: The hash is *not* published here - this process is following
+            # a change made elsewhere. If it published a different hash, other
+            # processes would reload again in turn, resulting in a reload loop.
+            if not self.reload_plugins(
+                full_reload=True, force_reload=True, collect=True, update_hash=False
+            ):
+                return False
+
+            # Re-read the hash, in case another process changed the registry state
+            # while this process was reloading
+            reg_hash = get_global_setting(
+                '_PLUGIN_REGISTRY_HASH', '', create=False, cache=False
+            )
+
+            self.check_registry_mismatch(reg_hash)
             return True
         finally:
             release_lease('_PLUGIN_REGISTRY_HASH')
 
+    def check_registry_mismatch(self, reg_hash: str) -> None:
+        """Check that this process reproduced the registry state published by another process.
+
+        If, after reloading, the local registry hash still does not match the hash
+        stored in the database, this process loaded a different set of plugins
+        (or plugin versions) to the process which published the hash.
+        Left unchecked, this results in an endless plugin reload loop.
+
+        A single mismatch can be caused by a concurrent change, so the reload is
+        retried. If the mismatch persists, the error is reported to the system
+        administrator, and this process stops reloading for that hash.
+
+        Args:
+            reg_hash: The registry hash currently stored in the database
+        """
+        if not reg_hash or reg_hash == self.registry_hash:
+            # Registry state matches - reset mismatch tracking
+            self.mismatch_hash = None
+            self.mismatch_count = 0
+            return
+
+        if reg_hash == self.mismatch_hash:
+            self.mismatch_count += 1
+        else:
+            self.mismatch_hash = reg_hash
+            self.mismatch_count = 1
+
+        logger.warning(
+            'Plugin registry hash mismatch after reload (attempt %s): expected %s, found %s',
+            self.mismatch_count,
+            reg_hash,
+            self.registry_hash,
+        )
+
+        if self.mismatch_count < self.MAX_MISMATCH_RELOADS:
+            return
+
+        process = (
+            'background worker' if InvenTree.ready.isInWorkerThread() else 'server'
+        )
+
+        plugins = '\n'.join(
+            f'- {slug}: {plugin.version}'
+            for slug, plugin in sorted(self.plugins.items(), key=lambda item: item[0])
+        )
+
+        log_error(
+            'check_reload',
+            scope='plugins',
+            error_name='Plugin Registry Mismatch',
+            error_info=(
+                f'INVE-E20: The plugin registry in this {process} process (pid {os.getpid()}) '
+                'does not match the plugin registry of other InvenTree processes. '
+                'Plugins may be out of sync between processes - '
+                'restart all InvenTree server and background worker processes.'
+            ),
+            error_data=(
+                f'Expected registry hash: {reg_hash}\n'
+                f'Local registry hash: {self.registry_hash}\n\n'
+                f'Loaded plugins:\n{plugins}'
+            ),
+        )
+
     # endregion
 
 
@@ -1218,26 +1347,3 @@ registry: PluginsRegistry = PluginsRegistry()
 def call_plugin_function(plugin_name: str, function_name: str, *args, **kwargs):
     """Global helper function to call a specific member function of a plugin."""
     return registry.call_plugin_function(plugin_name, function_name, *args, **kwargs)
-
-
-def _load_source(modname, filename):
-    """Helper function to replace deprecated & removed imp.load_source.
-
-    See https://docs.python.org/3/whatsnew/3.12.html#imp
-    """
-    if modname in sys.modules:
-        del sys.modules[modname]
-
-    # loader = importlib.machinery.SourceFileLoader(modname, filename)
-    spec = importlib.util.spec_from_file_location(modname, filename)  # , loader=loader)
-    if spec is None:
-        raise ImportError(f"Cannot find module '{modname}'")  # pragma: no cover
-    module = importlib.util.module_from_spec(spec)
-
-    sys.modules[module.__name__] = module
-
-    loader = spec.loader
-    if loader is not None:
-        loader.exec_module(module)
-
-    return module

src/backend/InvenTree/plugin/test_plugin.py

@@ -323,6 +323,83 @@ class RegistryTests(TestQueryMixin, PluginRegistryMixin, TestCase):
             # Run tests
             self.run_package_test(str(new_dir))
 
+    @override_settings(PLUGIN_TESTING_SETUP=True)
+    def test_package_update_reload(self):
+        """Test that reloading the registry picks up a plugin package updated on disk.
+
+        The plugin class reads its version from the package __init__.py
+        (as per the plugin-creator template), so reloading only the module
+        which defines the class would still report the old version.
+        """
+        import sys
+
+        tmp = Path(tempfile.mkdtemp())
+        self.addCleanup(shutil.rmtree, tmp, ignore_errors=True)
+
+        pkg = 'inventree_reload_test_plugin'
+
+        def write_package(version: str):
+            """Write the plugin package (and its dist-info) to disk."""
+            for dist_info in tmp.glob('*.dist-info'):
+                shutil.rmtree(dist_info)
+
+            src = tmp.joinpath(pkg)
+            src.mkdir(exist_ok=True)
+            src.joinpath('__init__.py').write_text(f"PLUGIN_VERSION = '{version}'\n")
+            src.joinpath('helper.py').write_text(f"LABEL = 'helper-{version}'\n")
+            src.joinpath('core.py').write_text(
+                textwrap.dedent("""
+                from plugin import InvenTreePlugin
+
+                from . import PLUGIN_VERSION
+                from .helper import LABEL
+
+
+                class ReloadTestPlugin(InvenTreePlugin):
+                    NAME = 'ReloadTestPlugin'
+                    SLUG = 'reload-test-plugin'
+                    VERSION = PLUGIN_VERSION
+                    LABEL = LABEL
+                """)
+            )
+
+            dist_info = tmp.joinpath(f'{pkg}-{version}.dist-info')
+            dist_info.mkdir()
+            dist_info.joinpath('METADATA').write_text(
+                f'Metadata-Version: 2.1\nName: {pkg}\nVersion: {version}\n'
+            )
+            dist_info.joinpath('entry_points.txt').write_text(
+                f'[inventree_plugins]\nReloadTestPlugin = {pkg}.core:ReloadTestPlugin\n'
+            )
+
+        def cleanup():
+            sys.path.remove(str(tmp))
+            for name in [n for n in sys.modules if n.split('.')[0] == pkg]:
+                del sys.modules[name]
+            registry.reload_plugins(full_reload=True, collect=True)
+
+        # Avoid stale bytecode, as the files are rewritten within the same second
+        self.enterContext(mock.patch.object(sys, 'dont_write_bytecode', True))
+
+        write_package('1.0.0')
+        sys.path.insert(0, str(tmp))
+        self.addCleanup(cleanup)
+
+        registry.reload_plugins(full_reload=True, collect=True)
+        plg = registry.get_plugin('reload-test-plugin', active=None)
+        self.assertEqual(plg.version, '1.0.0')
+        self.assertEqual(plg.LABEL, 'helper-1.0.0')
+        old_hash = registry.registry_hash
+
+        # Update the package on disk, and reload the registry
+        write_package('1.2.3')
+        registry.reload_plugins(full_reload=True, collect=True)
+
+        plg = registry.get_plugin('reload-test-plugin', active=None)
+        self.assertEqual(plg.version, '1.2.3')
+        self.assertEqual(plg.LABEL, 'helper-1.2.3')
+        self.assertNotEqual(registry.registry_hash, old_hash)
+
     @override_settings(PLUGIN_TESTING_SETUP=True)
     def test_package_loading(self):
         """Test that package distributed plugins work."""
@@ -610,6 +687,55 @@ class RegistryTests(TestQueryMixin, PluginRegistryMixin, TestCase):
             registry.registry_hash = 'abc'
             self.assertTrue(registry.check_reload())
 
+    def test_check_reload_mismatch(self):
+        """Test that a persistent registry hash mismatch is reported, rather than looping.
+
+        Simulates another process publishing a registry hash which this process
+        cannot reproduce (e.g. it has loaded a different plugin version).
+        """
+        from error_report.models import Error
+
+        from common.settings import get_global_setting, set_global_setting
+
+        def published_hash():
+            return get_global_setting(
+                '_PLUGIN_REGISTRY_HASH', '', create=False, cache=False
+            )
+
+        with self.settings(TESTING=False, PLUGIN_TESTING_RELOAD=True):
+            registry.reload_plugins(full_reload=True, collect=True, force_reload=True)
+            local_hash = registry.registry_hash
+
+            set_global_setting('_PLUGIN_REGISTRY_HASH', 'other-process-hash')
+            errors = Error.objects.filter(kind='Plugin Registry Mismatch')
+            self.assertEqual(errors.count(), 0)
+
+            # First reload does not reproduce the hash - retried, not yet reported
+            self.assertTrue(registry.check_reload())
+            self.assertEqual(registry.mismatch_count, 1)
+            self.assertEqual(errors.count(), 0)
+
+            # The following process must not publish its own hash (which would
+            # trigger the other process to reload in turn)
+            self.assertEqual(published_hash(), 'other-process-hash')
+            self.assertEqual(registry.registry_hash, local_hash)
+
+            # Second reload still does not match - the error is reported
+            self.assertTrue(registry.check_reload())
+            self.assertEqual(errors.count(), 1)
+            self.assertIn(local_hash, errors.first().data)
+
+            # No further reloads (or errors) for the same hash
+            self.assertFalse(registry.check_reload())
+            self.assertEqual(errors.count(), 1)
+
+            # Once the registry state matches again, mismatch tracking is reset
+            registry.registry_hash = 'abc'
+            set_global_setting('_PLUGIN_REGISTRY_HASH', local_hash)
+            self.assertTrue(registry.check_reload())
+            self.assertIsNone(registry.mismatch_hash)
+            self.assertEqual(registry.mismatch_count, 0)
+
     def test_registry_hash_order_independence(self):
         """Test that the registry hash does not depend on plugin iteration order.