diff --git a/src/backend/InvenTree/InvenTree/settings.py b/src/backend/InvenTree/InvenTree/settings.py index 0972fa3b896e..b9495804494b 100644 --- a/src/backend/InvenTree/InvenTree/settings.py +++ b/src/backend/InvenTree/InvenTree/settings.py @@ -1326,7 +1326,7 @@ ) # 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? diff --git a/src/backend/InvenTree/plugin/registry.py b/src/backend/InvenTree/plugin/registry.py index 15f01bd127f1..e2bfb31ef64a 100644 --- a/src/backend/InvenTree/plugin/registry.py +++ b/src/backend/InvenTree/plugin/registry.py @@ -219,51 +219,15 @@ def _load_plugins(self, full_reload: bool = False): """ 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(blocked_plugin) - self._activate_plugins(full_reload=full_reload) - registered_successful = True - except (OperationalError, ProgrammingError): # pragma: no cover - # Exception if the database has not been migrated yet - logger.info('Database not accessible while loading plugins') - break - except IntegrationPluginError as error: - 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 + try: + self._init_plugins() + self._activate_plugins(full_reload=full_reload) + except (OperationalError, ProgrammingError, IntegrityError): + # Exception if the database has not been migrated yet, or is not ready + pass + except IntegrationPluginError: + # Plugin specific error has already been handled + pass # ensure plugins_loaded is True self.plugins_loaded = True @@ -478,18 +442,13 @@ def install_plugin_file(self): # endregion # region general internal loading / activating / deactivating / unloading - def _init_plugins(self, disabled: str = None): - """Initialise all found plugins. + def _init_plugin(self, plugin, configs: dict): + """Initialise a single plugin. Args: - disabled (str, optional): Loading path of disabled app. Defaults to None. - - Raises: - error: IntegrationPluginError + plugin: Plugin module """ - # 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,6 +462,99 @@ def safe_reference(plugin, key: str, active: bool = True): self.plugins_inactive[key] = plugin.db self.plugins_full[key] = plugin + # These checks only use attributes - never use plugin supplied functions -> that would lead to arbitrary code execution!! + plg_name = plugin.NAME + plg_key = slugify( + plugin.SLUG if getattr(plugin, 'SLUG', None) else plg_name + ) # keys are slugs! + + logger.info("Loading plugin '%s'", plg_key) + + if plg_key in configs: + 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 = plugin.check_is_builtin() + + package_name = None + + # Extract plugin package name + if getattr(plugin, 'is_package', False): + package_name = getattr(plugin, 'package_name', None) + + # Auto-enable builtin plugins + if builtin and plg_db and not plg_db.active: + plg_db.active = True + plg_db.save() + + # Save the package_name attribute to the plugin + if plg_db.package_name != package_name: + plg_db.package_name = package_name + plg_db.save() + + # Determine if this plugin should be loaded: + # - If PLUGIN_TESTING is enabled + # - 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): + # 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 = 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 + plg_i.is_package = getattr(plg_i, 'is_package', False) + + plg_i.pk = plg_db.pk if plg_db else None + plg_i.db = plg_db + + # Run version check for plugin + if (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) + + p = plg_name + v = version.inventreeVersion() + _msg = _( + f"Plugin '{p}' is not compatible with the current InvenTree version {v}" + ) + if v := plg_i.MIN_VERSION: + _msg += _(f'Plugin requires at least version {v}') + if v := plg_i.MAX_VERSION: + _msg += _(f'Plugin requires at most version {v}') + # Log to error stack + log_error(_msg, reference='init') + else: + safe_reference(plugin=plg_i, key=plg_key) + else: # pragma: no cover + 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 @@ -510,102 +562,32 @@ def safe_reference(plugin, key: str, active: bool = True): # 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_key = slugify( - plg.SLUG if getattr(plg, 'SLUG', None) else plg_name - ) # keys are slugs! + # Attempt to load each individual plugin + attempts = settings.PLUGIN_RETRY - try: - 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 - plg.db = plg_db - - # Check if this is a 'builtin' plugin - builtin = plg.check_is_builtin() - - package_name = None - - # Extract plugin package name - if getattr(plg, 'is_package', False): - package_name = getattr(plg, 'package_name', None) - - # Auto-enable builtin plugins - if builtin and plg_db and not plg_db.active: - plg_db.active = True - plg_db.save() - - # Save the package_name attribute to the plugin - if plg_db.package_name != package_name: - plg_db.package_name = package_name - plg_db.save() - - # Determine if this plugin should be loaded: - # - If PLUGIN_TESTING is enabled - # - 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) + while attempts > 0: + attempts -= 1 try: - t_start = time.time() - plg_i: InvenTreePlugin = plg() - dt = time.time() - t_start - logger.debug('Loaded plugin `%s` in %.3fs', plg_name, dt) + 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' - ) # log error and raise it -> disable plugin - logger.warning('Plugin `%s` could not be loaded', plg_name) - - # Safe extra attributes - plg_i.is_package = getattr(plg_i, 'is_package', False) - - plg_i.pk = plg_db.pk if plg_db else None - plg_i.db = plg_db - - # Run version check for plugin - if ( - 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) - - p = plg_name - v = version.inventreeVersion() - _msg = _( - f"Plugin '{p}' is not compatible with the current InvenTree version {v}" + error, log_name='init', do_raise=settings.PLUGIN_TESTING ) - if v := plg_i.MIN_VERSION: - _msg += _(f'Plugin requires at least version {v}') - if v := plg_i.MAX_VERSION: - _msg += _(f'Plugin requires at most version {v}') - # Log to error stack - log_error(_msg, reference='init') - else: - safe_reference(plugin=plg_i, key=plg_key) - else: # pragma: no cover - safe_reference(plugin=plg, key=plg_key, active=False) + + 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.""" diff --git a/src/backend/InvenTree/plugin/test_plugin.py b/src/backend/InvenTree/plugin/test_plugin.py index cff4373975c0..4fe03ea1c9a5 100644 --- a/src/backend/InvenTree/plugin/test_plugin.py +++ b/src/backend/InvenTree/plugin/test_plugin.py @@ -273,15 +273,17 @@ def test_broken_samples(self): # 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'" )