mirror of
				https://github.com/inventree/InvenTree.git
				synced 2025-10-30 20:55:42 +00:00 
			
		
		
		
	Plugin install errors (#9876)
* Log plugin install errors * Log more errors * Format pip errors * Update error messages * Control if plugins file gets installed * Error handling * Fix typo * Logic fix for loading plugins * Adjust unit test --------- Co-authored-by: Matthias Mair <code@mjmair.com>
This commit is contained in:
		| @@ -15,7 +15,6 @@ from allauth.headless.adapter import DefaultHeadlessAdapter | ||||
| from allauth.headless.tokens.sessions import SessionTokenStrategy | ||||
| from allauth.socialaccount.adapter import DefaultSocialAccountAdapter | ||||
|  | ||||
| import InvenTree.helpers_model | ||||
| import InvenTree.sso | ||||
| from common.settings import get_global_setting | ||||
| from InvenTree.exceptions import log_error | ||||
| @@ -129,7 +128,6 @@ class RegistrationMixin: | ||||
|         mailoptions = mail_restriction.split(',') | ||||
|         for option in mailoptions: | ||||
|             if not option.startswith('@'): | ||||
|                 log_error('LOGIN_SIGNUP_MAIL_RESTRICTION is not configured correctly') | ||||
|                 raise forms.ValidationError( | ||||
|                     _('The provided primary email address is not valid.') | ||||
|                 ) | ||||
| @@ -172,7 +170,7 @@ class CustomAccountAdapter(RegistrationMixin, DefaultAccountAdapter): | ||||
|             except Exception: | ||||
|                 # An exception occurred while attempting to send email | ||||
|                 # Log it (for admin users) and return silently | ||||
|                 log_error('account email') | ||||
|                 log_error('send_mail', scope='auth') | ||||
|                 result = False | ||||
|  | ||||
|             return result | ||||
| @@ -208,7 +206,7 @@ class CustomSocialAccountAdapter(RegistrationMixin, DefaultSocialAccountAdapter) | ||||
|         path = request.path or 'sso' | ||||
|  | ||||
|         # Log the error to the database | ||||
|         log_error(path, error_name=error, error_data=exception) | ||||
|         log_error(path, error_name=error, error_data=exception, scope='auth') | ||||
|         logger.error("SSO error for provider '%s' - check admin error log", provider_id) | ||||
|  | ||||
|     def get_connect_redirect_url(self, request, socialaccount): | ||||
|   | ||||
| @@ -23,6 +23,7 @@ def log_error( | ||||
|     error_name=None, | ||||
|     error_info=None, | ||||
|     error_data=None, | ||||
|     scope: Optional[str] = None, | ||||
|     plugin: Optional[str] = None, | ||||
| ): | ||||
|     """Log an error to the database. | ||||
| @@ -31,11 +32,10 @@ def log_error( | ||||
|  | ||||
|     Arguments: | ||||
|         path: The 'path' (most likely a URL) associated with this error (optional) | ||||
|  | ||||
|     kwargs: | ||||
|         error_name: The name of the error (optional, overrides 'kind') | ||||
|         error_info: The error information (optional, overrides 'info') | ||||
|         error_data: The error data (optional, overrides 'data') | ||||
|         scope: The scope of the error (optional) | ||||
|         plugin: The plugin name associated with this error (optional) | ||||
|     """ | ||||
|     from error_report.models import Error | ||||
| @@ -69,6 +69,10 @@ def log_error( | ||||
|         # If a plugin is specified, prepend it to the path | ||||
|         path = f'plugin.{plugin}.{path}' | ||||
|  | ||||
|     if scope: | ||||
|         # If a scope is specified, prepend it to the path | ||||
|         path = f'{scope}:{path}' | ||||
|  | ||||
|     # Ensure the error information does not exceed field size limits | ||||
|     path = path[:200] | ||||
|     kind = kind[:128] | ||||
|   | ||||
| @@ -206,7 +206,7 @@ def offload_task( | ||||
|             return False | ||||
|         except Exception as exc: | ||||
|             raise_warning(f"WARNING: '{taskname}' not offloaded due to {exc!s}") | ||||
|             log_error('InvenTree.offload_task') | ||||
|             log_error('offload_task', scope='worker') | ||||
|             return False | ||||
|     else: | ||||
|         if callable(taskname): | ||||
| @@ -227,7 +227,7 @@ def offload_task( | ||||
|             try: | ||||
|                 _mod = importlib.import_module(app_mod) | ||||
|             except ModuleNotFoundError: | ||||
|                 log_error('InvenTree.offload_task') | ||||
|                 log_error('offload_task', scope='worker') | ||||
|                 raise_warning( | ||||
|                     f"WARNING: '{taskname}' not started - No module named '{app_mod}'" | ||||
|                 ) | ||||
| @@ -244,7 +244,7 @@ def offload_task( | ||||
|                 if not _func: | ||||
|                     _func = eval(func)  # pragma: no cover | ||||
|             except NameError: | ||||
|                 log_error('InvenTree.offload_task') | ||||
|                 log_error('offload_task', scope='worker') | ||||
|                 raise_warning( | ||||
|                     f"WARNING: '{taskname}' not started - No function named '{func}'" | ||||
|                 ) | ||||
| @@ -255,7 +255,7 @@ def offload_task( | ||||
|             with tracer.start_as_current_span(f'sync worker: {taskname}'): | ||||
|                 _func(*args, **kwargs) | ||||
|         except Exception as exc: | ||||
|             log_error('InvenTree.offload_task') | ||||
|             log_error('offload_task', scope='worker') | ||||
|             raise_warning(f"WARNING: '{taskname}' failed due to {exc!s}") | ||||
|             raise exc | ||||
|  | ||||
|   | ||||
| @@ -1191,11 +1191,16 @@ class TestSettings(InvenTreeTestCase): | ||||
|  | ||||
|     def test_initial_install(self): | ||||
|         """Test if install of plugins on startup works.""" | ||||
|         from common.settings import set_global_setting | ||||
|         from plugin import registry | ||||
|  | ||||
|         set_global_setting('PLUGIN_ON_STARTUP', True) | ||||
|  | ||||
|         registry.reload_plugins(full_reload=True, collect=True) | ||||
|         self.assertGreater(len(settings.PLUGIN_FILE_HASH), 0) | ||||
|  | ||||
|         set_global_setting('PLUGIN_ON_STARTUP', False) | ||||
|  | ||||
|     def test_helpers_cfg_file(self): | ||||
|         """Test get_config_file.""" | ||||
|         # normal run - not configured | ||||
|   | ||||
| @@ -100,7 +100,7 @@ class BarcodeView(CreateAPIView): | ||||
|                 BarcodeScanResult.objects.filter(pk__in=old_scan_ids).delete() | ||||
|         except Exception: | ||||
|             # Gracefully log error to database | ||||
|             log_error(f'{self.__class__.__name__}.log_scan') | ||||
|             log_error(f'{self.__class__.__name__}.log_scan', scope='barcode') | ||||
|  | ||||
|     def queryset(self): | ||||
|         """This API view does not have a queryset.""" | ||||
|   | ||||
| @@ -425,7 +425,7 @@ class SupplierBarcodeMixin(BarcodeMixin): | ||||
|                 response['error'] = e.message | ||||
|             except Exception: | ||||
|                 # Handle any other exceptions | ||||
|                 log_error('scan_receive_item') | ||||
|                 log_error('scan_receive_item', plugin=self.slug) | ||||
|                 response['error'] = _('Failed to receive line item') | ||||
|  | ||||
|         return response | ||||
|   | ||||
| @@ -51,7 +51,7 @@ class LabelPrintingMixin: | ||||
|         try: | ||||
|             return label.render(instance, request) | ||||
|         except Exception: | ||||
|             log_error('label.render_to_pdf') | ||||
|             log_error('render_to_pdf', plugin=self.slug) | ||||
|             raise ValidationError(_('Error rendering label to PDF')) | ||||
|  | ||||
|     def render_to_html(self, label: LabelTemplate, instance, request, **kwargs): | ||||
| @@ -65,7 +65,7 @@ class LabelPrintingMixin: | ||||
|         try: | ||||
|             return label.render_as_string(instance, request) | ||||
|         except Exception: | ||||
|             log_error('label.render_to_html') | ||||
|             log_error('render_to_html', plugin=self.slug) | ||||
|             raise ValidationError(_('Error rendering label to HTML')) | ||||
|  | ||||
|     def render_to_png(self, label: LabelTemplate, instance, request=None, **kwargs): | ||||
| @@ -99,7 +99,7 @@ class LabelPrintingMixin: | ||||
|         try: | ||||
|             return pdf2image.convert_from_bytes(pdf_data, **pdf2image_kwargs)[0] | ||||
|         except Exception: | ||||
|             log_error('label.render_to_png') | ||||
|             log_error('render_to_png', plugin=self.slug) | ||||
|             return None | ||||
|  | ||||
|     def print_labels( | ||||
|   | ||||
| @@ -49,7 +49,7 @@ class MixinNotImplementedError(NotImplementedError): | ||||
|     """Error if necessary mixin function was not overwritten.""" | ||||
|  | ||||
|  | ||||
| def log_error(error, reference: str = 'general'): | ||||
| def log_registry_error(error, reference: str = 'general'): | ||||
|     """Log an plugin error.""" | ||||
|     from plugin import registry | ||||
|  | ||||
| @@ -92,7 +92,7 @@ def handle_error(error, do_raise: bool = True, do_log: bool = True, log_name: st | ||||
|         log_kwargs = {} | ||||
|         if log_name: | ||||
|             log_kwargs['reference'] = log_name | ||||
|         log_error({package_name: str(error)}, **log_kwargs) | ||||
|         log_registry_error({package_name: str(error)}, **log_kwargs) | ||||
|  | ||||
|     if do_raise: | ||||
|         # do a straight raise if we are playing with environment variables at execution time, ignore the broken sample | ||||
| @@ -185,7 +185,7 @@ def get_modules(pkg, path=None): | ||||
|         except StopIteration: | ||||
|             break | ||||
|         except Exception as error: | ||||
|             log_error({pkg.__name__: str(error)}, 'discovery') | ||||
|             log_registry_error({pkg.__name__: str(error)}, 'discovery') | ||||
|             continue | ||||
|  | ||||
|         try: | ||||
| @@ -207,7 +207,7 @@ def get_modules(pkg, path=None): | ||||
|             # this 'protects' against malformed plugin modules by more or less silently failing | ||||
|  | ||||
|             # log to stack | ||||
|             log_error({name: str(error)}, 'discovery') | ||||
|             log_registry_error({name: str(error)}, 'discovery') | ||||
|  | ||||
|     return [v for k, v in context.items()] | ||||
|  | ||||
| @@ -217,7 +217,7 @@ def get_classes(module) -> list: | ||||
|     try: | ||||
|         return inspect.getmembers(module, inspect.isclass) | ||||
|     except Exception: | ||||
|         log_error({module.__name__: 'Could not get classes'}, 'discovery') | ||||
|         log_registry_error({module.__name__: 'Could not get classes'}, 'discovery') | ||||
|         return [] | ||||
|  | ||||
|  | ||||
|   | ||||
| @@ -47,7 +47,7 @@ def handle_pip_error(error, path: str) -> list: | ||||
|     - Format the output from a pip command into a list of error messages. | ||||
|     - Raise an appropriate error | ||||
|     """ | ||||
|     log_error(path) | ||||
|     log_error(path, scope='pip') | ||||
|  | ||||
|     output = error.output.decode('utf-8') | ||||
|  | ||||
| @@ -95,11 +95,13 @@ def get_install_info(packagename: str) -> dict: | ||||
|                 info[key] = value | ||||
|  | ||||
|     except subprocess.CalledProcessError as error: | ||||
|         log_error('get_install_info') | ||||
|         log_error('get_install_info', scope='pip') | ||||
|  | ||||
|         output = error.output.decode('utf-8') | ||||
|         info['error'] = output | ||||
|         logger.exception('Plugin lookup failed: %s', str(output)) | ||||
|     except Exception: | ||||
|         log_error('get_install_info', scope='pip') | ||||
|  | ||||
|     return info | ||||
|  | ||||
| @@ -113,9 +115,13 @@ def plugins_file_hash(): | ||||
|     if not pf or not pf.exists(): | ||||
|         return None | ||||
|  | ||||
|     with pf.open('rb') as f: | ||||
|         # Note: Once we support 3.11 as a minimum, we can use hashlib.file_digest | ||||
|         return hashlib.sha256(f.read()).hexdigest() | ||||
|     try: | ||||
|         with pf.open('rb') as f: | ||||
|             # Note: Once we support 3.11 as a minimum, we can use hashlib.file_digest | ||||
|             return hashlib.sha256(f.read()).hexdigest() | ||||
|     except Exception: | ||||
|         log_error('plugins_file_hash', scope='plugins') | ||||
|         return None | ||||
|  | ||||
|  | ||||
| def install_plugins_file(): | ||||
| @@ -135,15 +141,18 @@ def install_plugins_file(): | ||||
|     except subprocess.CalledProcessError as error: | ||||
|         output = error.output.decode('utf-8') | ||||
|         logger.exception('Plugin file installation failed: %s', str(output)) | ||||
|         log_error('pip') | ||||
|         log_error('install_plugins_file', scope='pip') | ||||
|         return False | ||||
|     except Exception as exc: | ||||
|         logger.exception('Plugin file installation failed: %s', exc) | ||||
|         log_error('pip') | ||||
|         log_error('install_plugins_file', scope='pip') | ||||
|         return False | ||||
|  | ||||
|     # Collect plugin static files | ||||
|     plugin.staticfiles.collect_plugins_static_files() | ||||
|     try: | ||||
|         plugin.staticfiles.collect_plugins_static_files() | ||||
|     except Exception: | ||||
|         log_error('collect_plugins_static_files', scope='plugins') | ||||
|  | ||||
|     # At this point, the plugins file has been installed | ||||
|     return True | ||||
| @@ -178,6 +187,7 @@ def update_plugins_file(install_name, full_package=None, version=None, remove=Fa | ||||
|             lines = f.readlines() | ||||
|     except Exception as exc: | ||||
|         logger.exception('Failed to read plugins file: %s', str(exc)) | ||||
|         log_error('update_plugins_file', scope='plugins') | ||||
|         return | ||||
|  | ||||
|     # Reconstruct output file | ||||
| @@ -214,6 +224,7 @@ def update_plugins_file(install_name, full_package=None, version=None, remove=Fa | ||||
|                     f.write('\n') | ||||
|     except Exception as exc: | ||||
|         logger.exception('Failed to add plugin to plugins file: %s', str(exc)) | ||||
|         log_error('update_plugins_file', scope='plugins') | ||||
|  | ||||
|  | ||||
| def install_plugin(url=None, packagename=None, user=None, version=None): | ||||
| @@ -276,6 +287,8 @@ def install_plugin(url=None, packagename=None, user=None, version=None): | ||||
|  | ||||
|     except subprocess.CalledProcessError as error: | ||||
|         handle_pip_error(error, 'plugin_install') | ||||
|     except Exception: | ||||
|         log_error('install_plugin', scope='plugins') | ||||
|  | ||||
|     if version := ret.get('version'): | ||||
|         # Save plugin to plugins file | ||||
| @@ -343,6 +356,8 @@ def uninstall_plugin(cfg: plugin.models.PluginConfig, user=None, delete_config=T | ||||
|             pip_command('uninstall', '-y', package_name) | ||||
|         except subprocess.CalledProcessError as error: | ||||
|             handle_pip_error(error, 'plugin_uninstall') | ||||
|         except Exception: | ||||
|             log_error('uninstall_plugin', scope='plugins') | ||||
|     else: | ||||
|         # No matching install target found | ||||
|         raise ValidationError(_('Plugin installation not found')) | ||||
|   | ||||
| @@ -5,7 +5,6 @@ | ||||
| """ | ||||
|  | ||||
| import importlib | ||||
| import importlib.machinery | ||||
| import importlib.util | ||||
| import os | ||||
| import sys | ||||
| @@ -29,6 +28,7 @@ import structlog | ||||
| import InvenTree.cache | ||||
| from common.settings import get_global_setting, set_global_setting | ||||
| from InvenTree.config import get_plugin_dir | ||||
| from InvenTree.exceptions import log_error | ||||
| from InvenTree.ready import canAppAccessDatabase | ||||
|  | ||||
| from .helpers import ( | ||||
| @@ -36,7 +36,7 @@ from .helpers import ( | ||||
|     get_entrypoints, | ||||
|     get_plugins, | ||||
|     handle_error, | ||||
|     log_error, | ||||
|     log_registry_error, | ||||
| ) | ||||
| from .plugin import InvenTreePlugin | ||||
|  | ||||
| @@ -334,6 +334,13 @@ class PluginsRegistry: | ||||
|         if clear_errors: | ||||
|             self.errors = {} | ||||
|  | ||||
|         try: | ||||
|             plugin_on_startup = get_global_setting( | ||||
|                 'PLUGIN_ON_STARTUP', create=False, cache=False | ||||
|             ) | ||||
|         except Exception: | ||||
|             plugin_on_startup = False | ||||
|  | ||||
|         try: | ||||
|             logger.info( | ||||
|                 'Plugin Registry: Reloading plugins - Force: %s, Full: %s, Collect: %s', | ||||
| @@ -342,9 +349,13 @@ class PluginsRegistry: | ||||
|                 collect, | ||||
|             ) | ||||
|  | ||||
|             if collect and not settings.PLUGINS_INSTALL_DISABLED: | ||||
|             # If we are in a container environment, reload the entire plugins file | ||||
|             if collect: | ||||
|                 logger.info('Collecting plugins') | ||||
|                 self.install_plugin_file() | ||||
|  | ||||
|                 if plugin_on_startup and not settings.PLUGINS_INSTALL_DISABLED: | ||||
|                     self.install_plugin_file() | ||||
|  | ||||
|                 self.plugin_modules = self.collect_plugins() | ||||
|  | ||||
|             self.plugins_loaded = False | ||||
| @@ -357,6 +368,7 @@ class PluginsRegistry: | ||||
|  | ||||
|         except Exception as e: | ||||
|             logger.exception('Expected error during plugin reload: %s', e) | ||||
|             log_error('reload_plugins', scope='plugins') | ||||
|  | ||||
|         finally: | ||||
|             # Ensure the lock is released always | ||||
| @@ -391,10 +403,11 @@ class PluginsRegistry: | ||||
|                     if not pd.exists(): | ||||
|                         try: | ||||
|                             pd.mkdir(exist_ok=True) | ||||
|                         except Exception:  # pragma: no cover | ||||
|                         except Exception as e:  # pragma: no cover | ||||
|                             logger.exception( | ||||
|                                 "Could not create plugin directory '%s'", pd | ||||
|                             ) | ||||
|                             log_registry_error(e, 'plugin_dirs') | ||||
|                             continue | ||||
|  | ||||
|                     # Ensure the directory has an __init__.py file | ||||
| @@ -407,6 +420,7 @@ class PluginsRegistry: | ||||
|                             logger.exception( | ||||
|                                 "Could not create file '%s'", init_filename | ||||
|                             ) | ||||
|                             log_error('plugin_dirs', scope='plugins') | ||||
|                             continue | ||||
|  | ||||
|                     # By this point, we have confirmed that the directory at least exists | ||||
| @@ -629,7 +643,7 @@ class PluginsRegistry: | ||||
|                 if v := plg_i.MAX_VERSION: | ||||
|                     _msg += _(f'Plugin requires at most version {v}') | ||||
|                 # Log to error stack | ||||
|                 log_error(_msg, reference=f'{p}:init_plugin') | ||||
|                 log_registry_error(_msg, reference=f'{p}:init_plugin') | ||||
|             else: | ||||
|                 safe_reference(plugin=plg_i, key=plg_key) | ||||
|         else:  # pragma: no cover | ||||
|   | ||||
| @@ -163,7 +163,7 @@ class ReportConfig(AppConfig): | ||||
|                 ) | ||||
|                 logger.info("Creating new label template: '%s'", template['name']) | ||||
|             except Exception: | ||||
|                 InvenTree.exceptions.log_error('create_default_labels') | ||||
|                 InvenTree.exceptions.log_error('create_default_labels', scope='init') | ||||
|  | ||||
|     def create_default_reports(self): | ||||
|         """Create default report templates.""" | ||||
| @@ -262,4 +262,4 @@ class ReportConfig(AppConfig): | ||||
|                 ) | ||||
|                 logger.info("Created new report template: '%s'", template['name']) | ||||
|             except Exception: | ||||
|                 InvenTree.exceptions.log_error('create_default_reports') | ||||
|                 InvenTree.exceptions.log_error('create_default_reports', scope='init') | ||||
|   | ||||
| @@ -570,7 +570,7 @@ class ReportTemplate(TemplateUploadMixin, ReportTemplateBase): | ||||
|         except Exception as exc: | ||||
|             # Something went wrong during the report generation process | ||||
|             if get_global_setting('REPORT_LOG_ERRORS', backup_value=True): | ||||
|                 InvenTree.exceptions.log_error('report.print') | ||||
|                 InvenTree.exceptions.log_error('print', plugin=self.slug) | ||||
|  | ||||
|             raise ValidationError({ | ||||
|                 'error': _('Error generating report'), | ||||
| @@ -601,7 +601,7 @@ class ReportTemplate(TemplateUploadMixin, ReportTemplateBase): | ||||
|                 data = pdf_file.getvalue() | ||||
|                 pdf_file.close() | ||||
|             except Exception: | ||||
|                 InvenTree.exceptions.log_error('report.print') | ||||
|                 InvenTree.exceptions.log_error('print', plugin=self.slug) | ||||
|                 data = None | ||||
|  | ||||
|         # Save the generated report to the database | ||||
|   | ||||
		Reference in New Issue
	
	Block a user