Plugin load fix (#7505) (#7507)

* Cast setting to int

* Prevent single faulty plugin from killing *all* plugins

* Handle specific errors on _load_plugins

* Update unit test

(cherry picked from commit da42fdf06e)

Co-authored-by: Oliver <oliver.henry.walters@gmail.com>

src/backend/InvenTree/InvenTree/settings.py

@@ -1326,7 +1326,7 @@ PLUGIN_TESTING_SETUP = get_setting(
 )  # Load plugins from setup hooks in testing?
 PLUGIN_TESTING_EVENTS = False  # Flag if events are tested right now
 PLUGIN_RETRY = get_setting(
-    'INVENTREE_PLUGIN_RETRY', 'PLUGIN_RETRY', 5
+    'INVENTREE_PLUGIN_RETRY', 'PLUGIN_RETRY', 3, typecast=int
 )  # How often should plugin loading be tried?
 PLUGIN_FILE_CHECKED = False  # Was the plugin file checked?
 

src/backend/InvenTree/plugin/registry.py

@@ -219,51 +219,15 @@ class PluginsRegistry:
         """
         logger.info('Loading plugins')
 
-        registered_successful = False
-        blocked_plugin = None
-        retry_counter = settings.PLUGIN_RETRY
-
-        while not registered_successful:
         try:
-                # We are using the db so for migrations etc we need to try this block
+            self._init_plugins()
-                self._init_plugins(blocked_plugin)
             self._activate_plugins(full_reload=full_reload)
-                registered_successful = True
+        except (OperationalError, ProgrammingError, IntegrityError):
-            except (OperationalError, ProgrammingError):  # pragma: no cover
+            # Exception if the database has not been migrated yet, or is not ready
-                # Exception if the database has not been migrated yet
+            pass
-                logger.info('Database not accessible while loading plugins')
+        except IntegrationPluginError:
-                break
+            # Plugin specific error has already been handled
-            except IntegrationPluginError as error:
+            pass
-                logger.exception(
-                    '[PLUGIN] Encountered an error with %s:\n%s',
-                    error.path,
-                    error.message,
-                )
-                log_error({error.path: error.message}, 'load')
-                blocked_plugin = error.path  # we will not try to load this app again
-
-                # Initialize apps without any plugins
-                self._clean_registry()
-                self._clean_installed_apps()
-                self._activate_plugins(force_reload=True, full_reload=full_reload)
-
-                # We do not want to end in an endless loop
-                retry_counter -= 1
-
-                if retry_counter <= 0:  # pragma: no cover
-                    if settings.PLUGIN_TESTING:
-                        print('[PLUGIN] Max retries, breaking loading')
-                    break
-                if settings.PLUGIN_TESTING:
-                    print(
-                        f'[PLUGIN] Above error occurred during testing - {retry_counter}/{settings.PLUGIN_RETRY} retries left'
-                    )
-
-                # now the loading will re-start up with init
-
-            # disable full reload after the first round
-            if full_reload:
-                full_reload = False
 
         # ensure plugins_loaded is True
         self.plugins_loaded = True
@@ -478,18 +442,13 @@ class PluginsRegistry:
     # endregion
 
     # region general internal loading / activating / deactivating / unloading
-    def _init_plugins(self, disabled: str = None):
+    def _init_plugin(self, plugin, configs: dict):
-        """Initialise all found plugins.
+        """Initialise a single plugin.
 
         Args:
-            disabled (str, optional): Loading path of disabled app. Defaults to None.
+            plugin: Plugin module
-
-        Raises:
-            error: IntegrationPluginError
         """
-        # Imports need to be in this level to prevent early db model imports
         from InvenTree import version
-        from plugin.models import PluginConfig
 
         def safe_reference(plugin, key: str, active: bool = True):
             """Safe reference to plugin dicts."""
@@ -503,46 +462,29 @@ class PluginsRegistry:
                 self.plugins_inactive[key] = plugin.db
             self.plugins_full[key] = plugin
 
-        logger.debug('Starting plugin initialization')
-
-        # Fetch and cache list of existing plugin configuration instances
-        plugin_configs = {cfg.key: cfg for cfg in PluginConfig.objects.all()}
-
-        # Initialize plugins
-        for plg in self.plugin_modules:
         # These checks only use attributes - never use plugin supplied functions -> that would lead to arbitrary code execution!!
-            plg_name = plg.NAME
+        plg_name = plugin.NAME
         plg_key = slugify(
-                plg.SLUG if getattr(plg, 'SLUG', None) else plg_name
+            plugin.SLUG if getattr(plugin, 'SLUG', None) else plg_name
         )  # keys are slugs!
 
-            try:
+        logger.info("Loading plugin '%s'", plg_key)
-                if plg_key in plugin_configs:
-                    # Configuration already exists
-                    plg_db = plugin_configs[plg_key]
-                else:
-                    # Configuration needs to be created
-                    plg_db = self.get_plugin_config(plg_key, plg_name)
-            except (OperationalError, ProgrammingError) as error:
-                # Exception if the database has not been migrated yet - check if test are running - raise if not
-                if not settings.PLUGIN_TESTING:
-                    raise error  # pragma: no cover
-                plg_db = None
-            except IntegrityError as error:  # pragma: no cover
-                logger.exception('Error initializing plugin `%s`: %s', plg_name, error)
-                handle_error(error, log_name='init')
 
-            # Append reference to plugin
+        if plg_key in configs:
-            plg.db = plg_db
+            plg_db = configs[plg_key]
+        else:
+            plg_db = self.get_plugin_config(plg_key, plg_name)
+
+        plugin.db = plg_db
 
         # Check if this is a 'builtin' plugin
-            builtin = plg.check_is_builtin()
+        builtin = plugin.check_is_builtin()
 
         package_name = None
 
         # Extract plugin package name
-            if getattr(plg, 'is_package', False):
+        if getattr(plugin, 'is_package', False):
-                package_name = getattr(plg, 'package_name', None)
+            package_name = getattr(plugin, 'package_name', None)
 
         # Auto-enable builtin plugins
         if builtin and plg_db and not plg_db.active:
@@ -559,23 +501,19 @@ class PluginsRegistry:
         # - If this is a 'builtin' plugin
         # - If this plugin has been explicitly enabled by the user
         if settings.PLUGIN_TESTING or builtin or (plg_db and plg_db.active):
-                # Check if the plugin was blocked -> threw an error; option1: package, option2: file-based
-                if disabled and disabled in (plg.__name__, plg.__module__):
-                    safe_reference(plugin=plg, key=plg_key, active=False)
-                    continue  # continue -> the plugin is not loaded
-
             # Initialize package - we can be sure that an admin has activated the plugin
             logger.debug('Loading plugin `%s`', plg_name)
 
             try:
                 t_start = time.time()
-                    plg_i: InvenTreePlugin = plg()
+                plg_i: InvenTreePlugin = plugin()
                 dt = time.time() - t_start
                 logger.debug('Loaded plugin `%s` in %.3fs', plg_name, dt)
             except Exception as error:
                 handle_error(
                     error, log_name='init'
                 )  # log error and raise it -> disable plugin
+
                 logger.warning('Plugin `%s` could not be loaded', plg_name)
 
             # Safe extra attributes
@@ -585,9 +523,7 @@ class PluginsRegistry:
             plg_i.db = plg_db
 
             # Run version check for plugin
-                if (
+            if (plg_i.MIN_VERSION or plg_i.MAX_VERSION) and not plg_i.check_version():
-                    plg_i.MIN_VERSION or plg_i.MAX_VERSION
-                ) and not plg_i.check_version():
                 # Disable plugin
                 safe_reference(plugin=plg_i, key=plg_key, active=False)
 
@@ -605,7 +541,53 @@ class PluginsRegistry:
             else:
                 safe_reference(plugin=plg_i, key=plg_key)
         else:  # pragma: no cover
-                safe_reference(plugin=plg, key=plg_key, active=False)
+            safe_reference(plugin=plugin, key=plg_key, active=False)
+
+    def _init_plugins(self):
+        """Initialise all found plugins.
+
+        Args:
+            disabled (str, optional): Loading path of disabled app. Defaults to None.
+
+        Raises:
+            error: IntegrationPluginError
+        """
+        # Imports need to be in this level to prevent early db model imports
+        from plugin.models import PluginConfig
+
+        logger.debug('Starting plugin initialization')
+
+        # Fetch and cache list of existing plugin configuration instances
+        plugin_configs = {cfg.key: cfg for cfg in PluginConfig.objects.all()}
+
+        # Initialize plugins
+        for plg in self.plugin_modules:
+            # Attempt to load each individual plugin
+            attempts = settings.PLUGIN_RETRY
+
+            while attempts > 0:
+                attempts -= 1
+
+                try:
+                    self._init_plugin(plg, plugin_configs)
+                    break
+                except IntegrationPluginError as error:
+                    # Error has been handled downstream
+                    pass
+                except Exception as error:
+                    # Handle the error, log it and try again
+                    handle_error(
+                        error, log_name='init', do_raise=settings.PLUGIN_TESTING
+                    )
+
+                    if attempts == 0:
+                        logger.exception(
+                            '[PLUGIN] Encountered an error with %s:\n%s',
+                            error.path,
+                            str(error),
+                        )
+
+        logger.debug('Finished plugin initialization')
 
     def __get_mixin_order(self):
         """Returns a list of mixin classes, in the order that they should be activated."""

src/backend/InvenTree/plugin/test_plugin.py

@@ -273,15 +273,17 @@ class RegistryTests(TestCase):
             # Reload to rediscover plugins
             registry.reload_plugins(full_reload=True, collect=True)
 
-        self.assertEqual(len(registry.errors), 3)
+        self.assertEqual(len(registry.errors), 2)
+
         # There should be at least one discovery error in the module `broken_file`
         self.assertGreater(len(registry.errors.get('discovery')), 0)
         self.assertEqual(
             registry.errors.get('discovery')[0]['broken_file'],
             "name 'bb' is not defined",
         )
+
         # There should be at least one load error with an intentional KeyError
-        self.assertGreater(len(registry.errors.get('load')), 0)
+        self.assertGreater(len(registry.errors.get('init')), 0)
         self.assertEqual(
-            registry.errors.get('load')[0]['broken_sample'], "'This is a dummy error'"
+            registry.errors.get('init')[0]['broken_sample'], "'This is a dummy error'"
         )