From 71c416bafd9ce32010dc88838d22ce52d3611886 Mon Sep 17 00:00:00 2001 From: Matthias Mair Date: Thu, 28 Sep 2023 06:53:22 +0200 Subject: [PATCH] Add flake8-logging linting (#5620) * added flake8-logging to make logging more robust * fixed LOG005 warnings * fixed LOG008 warnings * fixed LOG011 warnings * fixed more LOG011 errors * added ignores for intentional logger.error calls * fixed even more LOG011 errors --- .pre-commit-config.yaml | 3 +- InvenTree/InvenTree/apps.py | 16 ++++----- InvenTree/InvenTree/config.py | 16 ++++----- InvenTree/InvenTree/conversion.py | 4 +-- InvenTree/InvenTree/forms.py | 6 ++-- .../management/commands/clean_settings.py | 4 +-- .../management/commands/rebuild_thumbnails.py | 10 +++--- InvenTree/InvenTree/middleware.py | 2 +- InvenTree/InvenTree/models.py | 6 ++-- InvenTree/InvenTree/sentry.py | 2 +- InvenTree/InvenTree/settings.py | 20 +++++------ InvenTree/InvenTree/social_auth_urls.py | 4 +-- InvenTree/InvenTree/tasks.py | 34 +++++++++---------- InvenTree/build/models.py | 8 ++--- InvenTree/build/tasks.py | 8 ++--- InvenTree/common/models.py | 10 +++--- InvenTree/common/notifications.py | 22 ++++++------ InvenTree/common/tasks.py | 6 ++-- InvenTree/label/apps.py | 12 +++---- InvenTree/order/models.py | 4 +-- InvenTree/part/apps.py | 2 +- InvenTree/part/models.py | 16 ++++----- InvenTree/part/serializers.py | 2 +- InvenTree/part/stocktake.py | 6 ++-- InvenTree/part/tasks.py | 16 ++++----- .../part/templatetags/inventree_extras.py | 2 +- InvenTree/part/templatetags/sso.py | 2 +- InvenTree/plugin/base/event/events.py | 12 +++---- InvenTree/plugin/base/integration/AppMixin.py | 4 +-- .../plugin/base/integration/ScheduleMixin.py | 8 ++--- .../plugin/base/integration/SettingsMixin.py | 2 +- InvenTree/plugin/base/integration/mixins.py | 2 +- InvenTree/plugin/base/label/label.py | 6 ++-- InvenTree/plugin/base/locate/mixins.py | 2 +- InvenTree/plugin/helpers.py | 2 +- InvenTree/plugin/registry.py | 28 +++++++-------- .../plugin/samples/event/event_sample.py | 2 +- .../plugin/samples/locate/locate_sample.py | 12 +++---- InvenTree/plugin/views.py | 2 +- InvenTree/report/apps.py | 6 ++-- InvenTree/report/models.py | 6 ++-- InvenTree/report/templatetags/report.py | 2 +- InvenTree/users/apps.py | 2 +- InvenTree/users/models.py | 10 +++--- docker/gunicorn.conf.py | 2 +- 45 files changed, 177 insertions(+), 176 deletions(-) diff --git a/.pre-commit-config.yaml b/.pre-commit-config.yaml index f5c18ed007..a4f4fbcbee 100644 --- a/.pre-commit-config.yaml +++ b/.pre-commit-config.yaml @@ -24,7 +24,8 @@ repos: 'flake8-docstrings', 'flake8-string-format', 'flake8-tidy-imports', - 'pep8-naming' + 'pep8-naming', + 'flake8-logging' ] - repo: https://github.com/pycqa/isort rev: '5.12.0' diff --git a/InvenTree/InvenTree/apps.py b/InvenTree/InvenTree/apps.py index e6c5c10c86..50659f6fa8 100644 --- a/InvenTree/InvenTree/apps.py +++ b/InvenTree/InvenTree/apps.py @@ -99,7 +99,7 @@ class InvenTreeConfig(AppConfig): force_async=True, ) - logger.info(f"Started {len(tasks)} scheduled background tasks...") + logger.info("Started %s scheduled background tasks...", len(tasks)) def collect_tasks(self): """Collect all background tasks.""" @@ -112,7 +112,7 @@ class InvenTreeConfig(AppConfig): try: import_module(f'{app.module.__package__}.tasks') except Exception as e: # pragma: no cover - logger.error(f"Error loading tasks for {app_name}: {e}") + logger.exception("Error loading tasks for %s: %s", app_name, e) def update_exchange_rates(self): # pragma: no cover """Update exchange rates each time the server is started. @@ -148,7 +148,7 @@ class InvenTreeConfig(AppConfig): # Backend currency has changed? if base_currency != backend.base_currency: - logger.info(f"Base currency changed from {backend.base_currency} to {base_currency}") + logger.info("Base currency changed from %s to %s", backend.base_currency, base_currency) update = True except (ExchangeBackend.DoesNotExist): @@ -165,7 +165,7 @@ class InvenTreeConfig(AppConfig): except OperationalError: logger.warning("Could not update exchange rates - database not ready") except Exception as e: - logger.error(f"Error updating exchange rates: {e} ({type(e)})") + logger.exception("Error updating exchange rates: %s (%s)", e, type(e)) def add_user_on_startup(self): """Add a user on startup.""" @@ -192,7 +192,7 @@ class InvenTreeConfig(AppConfig): # not all needed variables set if set_variables < 3: - logger.warn('Not all required settings for adding a user on startup are present:\nINVENTREE_ADMIN_USER, INVENTREE_ADMIN_EMAIL, INVENTREE_ADMIN_PASSWORD') + logger.warning('Not all required settings for adding a user on startup are present:\nINVENTREE_ADMIN_USER, INVENTREE_ADMIN_EMAIL, INVENTREE_ADMIN_PASSWORD') settings.USER_ADDED = True return @@ -201,12 +201,12 @@ class InvenTreeConfig(AppConfig): try: with transaction.atomic(): if user.objects.filter(username=add_user).exists(): - logger.info(f"User {add_user} already exists - skipping creation") + logger.info("User %s already exists - skipping creation", add_user) else: new_user = user.objects.create_superuser(add_user, add_email, add_password) - logger.info(f'User {str(new_user)} was created!') + logger.info('User %s was created!', str(new_user)) except IntegrityError: - logger.warning(f'The user "{add_user}" could not be created') + logger.warning('The user "%s" could not be created', add_user) # do not try again settings.USER_ADDED = True diff --git a/InvenTree/InvenTree/config.py b/InvenTree/InvenTree/config.py index 4e54f62a19..b1e037abe7 100644 --- a/InvenTree/InvenTree/config.py +++ b/InvenTree/InvenTree/config.py @@ -51,7 +51,7 @@ def to_dict(value): try: return json.loads(value) except Exception as error: - logger.error(f"Failed to parse value '{value}' as JSON with error {error}. Ensure value is a valid JSON string.") + logger.exception("Failed to parse value '%s' as JSON with error %s. Ensure value is a valid JSON string.", value, error) return {} @@ -159,7 +159,7 @@ def get_setting(env_var=None, config_key=None, default_value=None, typecast=None set_metadata(source) return val except Exception as error: - logger.error(f"Failed to typecast '{env_var}' with value '{value}' to type '{typecast}' with error {error}") + logger.exception("Failed to typecast '%s' with value '%s' to type '%s' with error %s", env_var, value, typecast, error) set_metadata(source) return value @@ -272,7 +272,7 @@ def get_plugin_file(): if not plugin_file.exists(): logger.warning("Plugin configuration file does not exist - creating default file") - logger.info(f"Creating plugin file at '{plugin_file}'") + logger.info("Creating plugin file at '%s'", plugin_file) ensure_dir(plugin_file.parent) # If opening the file fails (no write permission, for example), then this will throw an error @@ -311,7 +311,7 @@ def get_secret_key(): secret_key_file = get_base_dir().joinpath("secret_key.txt").resolve() if not secret_key_file.exists(): - logger.info(f"Generating random key file at '{secret_key_file}'") + logger.info("Generating random key file at '%s'", secret_key_file) ensure_dir(secret_key_file.parent) # Create a random key file @@ -319,7 +319,7 @@ def get_secret_key(): key = ''.join([random.choice(options) for i in range(100)]) secret_key_file.write_text(key) - logger.info(f"Loading SECRET_KEY from '{secret_key_file}'") + logger.info("Loading SECRET_KEY from '%s'", secret_key_file) key_data = secret_key_file.read_text().strip() @@ -342,12 +342,12 @@ def get_custom_file(env_ref: str, conf_ref: str, log_ref: str, lookup_media: boo static_storage = StaticFilesStorage() if static_storage.exists(value): - logger.info(f"Loading {log_ref} from static directory: {value}") + logger.info("Loading %s from %s directory: %s", log_ref, 'static', value) elif lookup_media and default_storage.exists(value): - logger.info(f"Loading {log_ref} from media directory: {value}") + logger.info("Loading %s from %s directory: %s", log_ref, 'media', value) else: add_dir_str = ' or media' if lookup_media else '' - logger.warning(f"The {log_ref} file '{value}' could not be found in the static{add_dir_str} directories") + logger.warning("The %s file '%s' could not be found in the static %s directories", log_ref, value, add_dir_str) value = False return value diff --git a/InvenTree/InvenTree/conversion.py b/InvenTree/InvenTree/conversion.py index 922703d900..0b66e2df9e 100644 --- a/InvenTree/InvenTree/conversion.py +++ b/InvenTree/InvenTree/conversion.py @@ -55,7 +55,7 @@ def reload_unit_registry(): try: reg.define(cu.fmt_string()) except Exception as e: - logger.error(f'Failed to load custom unit: {cu.fmt_string()} - {e}') + logger.exception('Failed to load custom unit: %s - %s', cu.fmt_string(), e) # Once custom units are loaded, save registry _unit_registry = reg @@ -65,7 +65,7 @@ def reload_unit_registry(): pass dt = time.time() - t_start - logger.debug(f'Loaded unit registry in {dt:.3f}s') + logger.debug('Loaded unit registry in %s.3f s', dt) return reg diff --git a/InvenTree/InvenTree/forms.py b/InvenTree/InvenTree/forms.py index 6d55d8f583..7e543e1927 100644 --- a/InvenTree/InvenTree/forms.py +++ b/InvenTree/InvenTree/forms.py @@ -252,7 +252,7 @@ class RegistratonMixin: split_email = email.split('@') if len(split_email) != 2: - logger.error(f'The user {email} has an invalid email address') + logger.error('The user %s has an invalid email address', email) raise forms.ValidationError(_('The provided primary email address is not valid.')) mailoptions = mail_restriction.split(',') @@ -264,7 +264,7 @@ class RegistratonMixin: if split_email[1] == option[1:]: return super().clean_email(email) - logger.info(f'The provided email domain for {email} is not approved') + logger.info('The provided email domain for %s is not approved', email) raise forms.ValidationError(_('The provided email domain is not approved.')) def save_user(self, request, user, form, commit=True): @@ -279,7 +279,7 @@ class RegistratonMixin: group = Group.objects.get(id=start_group) user.groups.add(group) except Group.DoesNotExist: - logger.error('The setting `SIGNUP_GROUP` contains an non existent group', start_group) + logger.exception('The setting `SIGNUP_GROUP` contains an non existent group', start_group) user.save() return user diff --git a/InvenTree/InvenTree/management/commands/clean_settings.py b/InvenTree/InvenTree/management/commands/clean_settings.py index 77cc444422..4ef8269f24 100644 --- a/InvenTree/InvenTree/management/commands/clean_settings.py +++ b/InvenTree/InvenTree/management/commands/clean_settings.py @@ -23,7 +23,7 @@ class Command(BaseCommand): for setting in db_settings: if setting.key not in model_settings: setting.delete() - logger.info(f"deleted setting '{setting.key}'") + logger.info("deleted setting '%s'", setting.key) # user settings db_settings = InvenTreeUserSetting.objects.all() @@ -33,6 +33,6 @@ class Command(BaseCommand): for setting in db_settings: if setting.key not in model_settings: setting.delete() - logger.info(f"deleted user setting '{setting.key}'") + logger.info("deleted user setting '%s'", setting.key) logger.info("checked all settings") diff --git a/InvenTree/InvenTree/management/commands/rebuild_thumbnails.py b/InvenTree/InvenTree/management/commands/rebuild_thumbnails.py index 28f17228e2..102a9e1bf1 100644 --- a/InvenTree/InvenTree/management/commands/rebuild_thumbnails.py +++ b/InvenTree/InvenTree/management/commands/rebuild_thumbnails.py @@ -26,14 +26,14 @@ class Command(BaseCommand): img = model.image - logger.info(f"Generating thumbnail image for '{img}'") + logger.info("Generating thumbnail image for '%s'", img) try: model.image.render_variations(replace=False) except FileNotFoundError: - logger.warning(f"Warning: Image file '{img}' is missing") + logger.warning("Warning: Image file '%s' is missing", img) except UnidentifiedImageError: - logger.warning(f"Warning: Image file '{img}' is not a valid image") + logger.warning("Warning: Image file '%s' is not a valid image", img) def handle(self, *args, **kwargs): """Rebuild all thumbnail images.""" @@ -43,7 +43,7 @@ class Command(BaseCommand): try: self.rebuild_thumbnail(part) except (OperationalError, ProgrammingError): - logger.error("ERROR: Database read error.") + logger.exception("ERROR: Database read error.") break logger.info("Rebuilding Company thumbnails") @@ -52,5 +52,5 @@ class Command(BaseCommand): try: self.rebuild_thumbnail(company) except (OperationalError, ProgrammingError): - logger.error("ERROR: abase read error.") + logger.exception("ERROR: abase read error.") break diff --git a/InvenTree/InvenTree/middleware.py b/InvenTree/InvenTree/middleware.py index a5b7c8474b..887551dc59 100644 --- a/InvenTree/InvenTree/middleware.py +++ b/InvenTree/InvenTree/middleware.py @@ -82,7 +82,7 @@ class AuthRequiredMiddleware(object): authorized = True except Token.DoesNotExist: - logger.warning(f"Access denied for unknown token {token_key}") + logger.warning("Access denied for unknown token %s", token_key) # No authorization was found for the request if not authorized: diff --git a/InvenTree/InvenTree/models.py b/InvenTree/InvenTree/models.py index 85a595a9ce..8ef5eb03d5 100644 --- a/InvenTree/InvenTree/models.py +++ b/InvenTree/InvenTree/models.py @@ -535,7 +535,7 @@ class InvenTreeAttachment(models.Model): # Check that there are no directory tricks going on... if new_file.parent != attachment_dir: - logger.error(f"Attempted to rename attachment outside valid directory: '{new_file}'") + logger.error("Attempted to rename attachment outside valid directory: '%s'", new_file) raise ValidationError(_("Invalid attachment directory")) # Ignore further checks if the filename is not actually being renamed @@ -552,7 +552,7 @@ class InvenTreeAttachment(models.Model): raise ValidationError(_("Filename missing extension")) if not old_file.exists(): - logger.error(f"Trying to rename attachment '{old_file}' which does not exist") + logger.error("Trying to rename attachment '%s' which does not exist", old_file) return if new_file.exists(): @@ -955,4 +955,4 @@ def after_error_logged(sender, instance: Error, created: bool, **kwargs): except Exception as exc: """We do not want to throw an exception while reporting an exception""" - logger.error(exc) + logger.error(exc) # noqa: LOG005 diff --git a/InvenTree/InvenTree/sentry.py b/InvenTree/InvenTree/sentry.py index 88d49e0f0c..25cb25e016 100644 --- a/InvenTree/InvenTree/sentry.py +++ b/InvenTree/InvenTree/sentry.py @@ -60,7 +60,7 @@ def report_exception(exc): if settings.SENTRY_ENABLED and settings.SENTRY_DSN: if not any(isinstance(exc, e) for e in sentry_ignore_errors()): - logger.info(f"Reporting exception to sentry.io: {exc}") + logger.info("Reporting exception to sentry.io: %s", exc) try: sentry_sdk.capture_exception(exc) diff --git a/InvenTree/InvenTree/settings.py b/InvenTree/InvenTree/settings.py index cc21662be9..e4b903d11d 100644 --- a/InvenTree/InvenTree/settings.py +++ b/InvenTree/InvenTree/settings.py @@ -454,7 +454,7 @@ for key in db_keys: try: env_var = int(env_var) except ValueError: - logger.error(f"Invalid number for {env_key}: {env_var}") + logger.exception("Invalid number for %s: %s", env_key, env_var) # Override configuration value db_config[key] = env_var @@ -495,9 +495,9 @@ if 'sqlite' in db_engine: db_name = str(Path(db_name).resolve()) db_config['NAME'] = db_name -logger.info(f"DB_ENGINE: {db_engine}") -logger.info(f"DB_NAME: {db_name}") -logger.info(f"DB_HOST: {db_host}") +logger.info("DB_ENGINE: ", db_engine) +logger.info("DB_NAME: ", db_name) +logger.info("DB_HOST: ", db_host) """ In addition to base-level database configuration, we may wish to specify specific options to the database backend @@ -821,7 +821,7 @@ CURRENCY_DECIMAL_PLACES = 6 # Check that each provided currency is supported for currency in CURRENCIES: if currency not in moneyed.CURRENCIES: # pragma: no cover - logger.error(f"Currency code '{currency}' is not supported") + logger.error("Currency code '%s' is not supported", currency) sys.exit(1) # Custom currency exchange backend @@ -971,7 +971,7 @@ PLUGIN_FILE_CHECKED = False SITE_URL = get_setting('INVENTREE_SITE_URL', 'site_url', None) if SITE_URL: - logger.info(f"Site URL: {SITE_URL}") + logger.info("Site URL: ", SITE_URL) # Check that the site URL is valid validator = URLValidator() @@ -990,8 +990,8 @@ PUI_SETTINGS = get_setting("INVENTREE_PUI_SETTINGS", "pui_settings", {}) if DEBUG: logger.info("InvenTree running with DEBUG enabled") -logger.info(f"MEDIA_ROOT: '{MEDIA_ROOT}'") -logger.info(f"STATIC_ROOT: '{STATIC_ROOT}'") +logger.info("MEDIA_ROOT: '%s'", MEDIA_ROOT) +logger.info("STATIC_ROOT: '%s'", STATIC_ROOT) # Flags FLAGS = { @@ -1008,9 +1008,9 @@ FLAGS = { CUSTOM_FLAGS = get_setting('INVENTREE_FLAGS', 'flags', None, typecast=dict) if CUSTOM_FLAGS: if not isinstance(CUSTOM_FLAGS, dict): - logger.error(f"Invalid custom flags, must be valid dict: {CUSTOM_FLAGS}") + logger.error("Invalid custom flags, must be valid dict: ", CUSTOM_FLAGS) else: - logger.info(f"Custom flags: {CUSTOM_FLAGS}") + logger.info("Custom flags: ". CUSTOM_FLAGS) FLAGS.update(CUSTOM_FLAGS) # Magic login django-sesame diff --git a/InvenTree/InvenTree/social_auth_urls.py b/InvenTree/InvenTree/social_auth_urls.py index 78fed2f7c1..b9a55109bd 100644 --- a/InvenTree/InvenTree/social_auth_urls.py +++ b/InvenTree/InvenTree/social_auth_urls.py @@ -84,12 +84,12 @@ for provider in providers.registry.get_list(): urls = handle_oauth2(adapter=adapters[0]) else: if provider.id in legacy: - logger.warning(f'`{provider.id}` is not supported on platform UI. Use `{legacy[provider.id]}` instead.') + logger.warning('`%s` is not supported on platform UI. Use `%s` instead.', provider.id, legacy[provider.id]) continue elif provider.id == 'keycloak': urls = handle_keycloak() else: - logger.error(f'Found handler that is not yet ready for platform UI: `{provider.id}`. Open an feature request on GitHub if you need it implemented.') + logger.error('Found handler that is not yet ready for platform UI: `%s`. Open an feature request on GitHub if you need it implemented.', provider.id) continue provider_urlpatterns += [path(f'{provider.id}/', include(urls))] diff --git a/InvenTree/InvenTree/tasks.py b/InvenTree/InvenTree/tasks.py index 37e891f062..cba7dffbf5 100644 --- a/InvenTree/InvenTree/tasks.py +++ b/InvenTree/InvenTree/tasks.py @@ -48,11 +48,11 @@ def schedule_task(taskname, **kwargs): # If this task is already scheduled, don't schedule it again # Instead, update the scheduling parameters if Schedule.objects.filter(func=taskname).exists(): - logger.debug(f"Scheduled task '{taskname}' already exists - updating!") + logger.debug("Scheduled task '%s' already exists - updating!", taskname) Schedule.objects.filter(func=taskname).update(**kwargs) else: - logger.info(f"Creating scheduled task '{taskname}'") + logger.info("Creating scheduled task '%s'", taskname) Schedule.objects.create( name=taskname, @@ -94,7 +94,7 @@ def check_daily_holdoff(task_name: str, n_days: int = 1) -> bool: from InvenTree.ready import isInTestMode if n_days <= 0: - logger.info(f"Specified interval for task '{task_name}' < 1 - task will not run") + logger.info("Specified interval for task '%s' < 1 - task will not run", task_name) return False # Sleep a random number of seconds to prevent worker conflict @@ -117,7 +117,7 @@ def check_daily_holdoff(task_name: str, n_days: int = 1) -> bool: threshold = datetime.now() - timedelta(days=n_days) if last_success > threshold: - logger.info(f"Last successful run for '{task_name}' was too recent - skipping task") + logger.info("Last successful run for '%s' was too recent - skipping task", task_name) return False # Check for any information we have about this task @@ -134,7 +134,7 @@ def check_daily_holdoff(task_name: str, n_days: int = 1) -> bool: threshold = datetime.now() - timedelta(hours=12) if last_attempt > threshold: - logger.info(f"Last attempt for '{task_name}' was too recent - skipping task") + logger.info("Last attempt for '%s' was too recent - skipping task", task_name) return False # Record this attempt @@ -149,7 +149,7 @@ def record_task_attempt(task_name: str): from common.models import InvenTreeSetting - logger.info(f"Logging task attempt for '{task_name}'") + logger.info("Logging task attempt for '%s'", task_name) InvenTreeSetting.set_setting(f'_{task_name}_ATTEMPT', datetime.now().isoformat(), None) @@ -176,7 +176,7 @@ def offload_task(taskname, *args, force_async=False, force_sync=False, **kwargs) from InvenTree.status import is_worker_running except AppRegistryNotReady: # pragma: no cover - logger.warning(f"Could not offload task '{taskname}' - app registry not ready") + logger.warning("Could not offload task '%s' - app registry not ready", taskname) return except (OperationalError, ProgrammingError): # pragma: no cover raise_warning(f"Could not offload task '{taskname}' - database not ready") @@ -342,7 +342,7 @@ def delete_successful_tasks(): ) if results.count() > 0: - logger.info(f"Deleting {results.count()} successful task records") + logger.info("Deleting %s successful task records", results.count()) results.delete() except AppRegistryNotReady: # pragma: no cover @@ -367,7 +367,7 @@ def delete_failed_tasks(): ) if results.count() > 0: - logger.info(f"Deleting {results.count()} failed task records") + logger.info("Deleting %s failed task records", results.count()) results.delete() except AppRegistryNotReady: # pragma: no cover @@ -390,7 +390,7 @@ def delete_old_error_logs(): ) if errors.count() > 0: - logger.info(f"Deleting {errors.count()} old error logs") + logger.info("Deleting %s old error logs", errors.count()) errors.delete() except AppRegistryNotReady: # pragma: no cover @@ -414,7 +414,7 @@ def delete_old_notifications(): ) if items.count() > 0: - logger.info(f"Deleted {items.count()} old notification entries") + logger.info("Deleted %s old notification entries", items.count()) items.delete() items = NotificationMessage.objects.filter( @@ -422,7 +422,7 @@ def delete_old_notifications(): ) if items.count() > 0: - logger.info(f"Deleted {items.count()} old notification messages") + logger.info("Deleted %s old notification messages", items.count()) items.delete() except AppRegistryNotReady: @@ -474,7 +474,7 @@ def check_for_updates(): match = re.match(r"^.*(\d+)\.(\d+)\.(\d+).*$", tag) if len(match.groups()) != 3: # pragma: no cover - logger.warning(f"Version '{tag}' did not match expected pattern") + logger.warning("Version '%s' did not match expected pattern", tag) return latest_version = [int(x) for x in match.groups()] @@ -482,7 +482,7 @@ def check_for_updates(): if len(latest_version) != 3: raise ValueError(f"Version '{tag}' is not correct format") # pragma: no cover - logger.info(f"Latest InvenTree version: '{tag}'") + logger.info("Latest InvenTree version: '%s'", tag) # Save the version to the database common.models.InvenTreeSetting.set_setting( @@ -513,7 +513,7 @@ def update_exchange_rates(): backend = InvenTreeExchange() base = currency_code_default() - logger.info(f"Updating exchange rates using base currency '{base}'") + logger.info("Updating exchange rates using base currency '%s'", base) try: backend.update_rates(base_currency=base) @@ -523,7 +523,7 @@ def update_exchange_rates(): except OperationalError: logger.warning("Could not update exchange rates - database not ready") except Exception as e: # pragma: no cover - logger.error(f"Error updating exchange rates: {e} ({type(e)})") + logger.exception("Error updating exchange rates: %s (%s)", e, type(e)) @scheduled_task(ScheduledTask.DAILY) @@ -597,7 +597,7 @@ def check_for_migrations(worker: bool = True): except NotSupportedError as e: # pragma: no cover if settings.DATABASES['default']['ENGINE'] != 'django.db.backends.sqlite3': raise e - logger.error(f'Error during migrations: {e}') + logger.exception('Error during migrations: %s', e) print('Migrations done') logger.info('Ran migrations') diff --git a/InvenTree/build/models.py b/InvenTree/build/models.py index 6e1fd58939..33a9b8f9cd 100644 --- a/InvenTree/build/models.py +++ b/InvenTree/build/models.py @@ -1164,13 +1164,13 @@ class Build(MPTTModel, InvenTree.models.InvenTreeBarcodeMixin, InvenTree.models. bom_items = self.part.get_bom_items() - logger.info(f"Creating BuildLine objects for BuildOrder {self.pk} ({len(bom_items)} items))") + logger.info("Creating BuildLine objects for BuildOrder %s (%s items)", self.pk, len(bom_items)) # Iterate through each part required to build the parent part for bom_item in bom_items: if prevent_duplicates: if BuildLine.objects.filter(build=self, bom_item=bom_item).exists(): - logger.info(f"BuildLine already exists for BuildOrder {self.pk} and BomItem {bom_item.pk}") + logger.info("BuildLine already exists for BuildOrder %s and BomItem %s", self.pk, bom_item.pk) continue # Calculate required quantity @@ -1187,7 +1187,7 @@ class Build(MPTTModel, InvenTree.models.InvenTreeBarcodeMixin, InvenTree.models. BuildLine.objects.bulk_create(lines) if len(lines) > 0: - logger.info(f"Created {len(lines)} BuildLine objects for BuildOrder") + logger.info("Created %s BuildLine objects for BuildOrder", len(lines)) @transaction.atomic def update_build_line_items(self): @@ -1201,7 +1201,7 @@ class Build(MPTTModel, InvenTree.models.InvenTreeBarcodeMixin, InvenTree.models. BuildLine.objects.bulk_update(lines_to_update, ['quantity']) - logger.info(f"Updated {len(lines_to_update)} BuildLine objects for BuildOrder") + logger.info("Updated %s BuildLine objects for BuildOrder", len(lines_to_update)) @receiver(post_save, sender=Build, dispatch_uid='build_post_save_log') diff --git a/InvenTree/build/tasks.py b/InvenTree/build/tasks.py index 95e7baa474..763e26af1c 100644 --- a/InvenTree/build/tasks.py +++ b/InvenTree/build/tasks.py @@ -30,7 +30,7 @@ def update_build_order_lines(bom_item_pk: int): This task is triggered when a BomItem is created or updated. """ - logger.info(f"Updating build order lines for BomItem {bom_item_pk}") + logger.info("Updating build order lines for BomItem %s", bom_item_pk) bom_item = part_models.BomItem.objects.filter(pk=bom_item_pk).first() @@ -70,7 +70,7 @@ def update_build_order_lines(bom_item_pk: int): ) if builds.count() > 0: - logger.info(f"Updated {builds.count()} build orders for part {bom_item.part}") + logger.info("Updated %s build orders for part %s", builds.count(), bom_item.part) def check_build_stock(build: build.models.Build): @@ -94,7 +94,7 @@ def check_build_stock(build: build.models.Build): part = build.part except part_models.Part.DoesNotExist: # Note: This error may be thrown during unit testing... - logger.error("Invalid build.part passed to 'build.tasks.check_build_stock'") + logger.exception("Invalid build.part passed to 'build.tasks.check_build_stock'") return for bom_item in part.get_bom_items(): @@ -135,7 +135,7 @@ def check_build_stock(build: build.models.Build): if len(emails) > 0: - logger.info(f"Notifying users of stock required for build {build.pk}") + logger.info("Notifying users of stock required for build %s", build.pk) context = { 'link': InvenTree.helpers_model.construct_absolute_url(build.get_absolute_url()), diff --git a/InvenTree/common/models.py b/InvenTree/common/models.py index d35bcf8827..f78458ad82 100644 --- a/InvenTree/common/models.py +++ b/InvenTree/common/models.py @@ -227,7 +227,7 @@ class BaseInvenTreeSetting(models.Model): if self.pk is None: return - logger.debug(f"Saving setting '{ckey}' to cache") + logger.debug("Saving setting '%s' to cache", ckey) try: cache.set( @@ -769,19 +769,19 @@ class BaseInvenTreeSetting(models.Model): try: (app, mdl) = model_name.strip().split('.') except ValueError: - logger.error(f"Invalid 'model' parameter for setting {self.key} : '{model_name}'") + logger.exception("Invalid 'model' parameter for setting '%s': '%s'", self.key, model_name) return None app_models = apps.all_models.get(app, None) if app_models is None: - logger.error(f"Error retrieving model class '{model_name}' for setting '{self.key}' - no app named '{app}'") + logger.error("Error retrieving model class '%s' for setting '%s' - no app named '%s'", model_name, self.key, app) return None model = app_models.get(mdl, None) if model is None: - logger.error(f"Error retrieving model class '{model_name}' for setting '{self.key}' - no model named '{mdl}'") + logger.error("Error retrieving model class '%s' for setting '%s' - no model named '%s'", model_name, self.key, mdl) return None # Looks like we have found a model! @@ -2269,7 +2269,7 @@ class PriceBreak(MetaMixin): try: converted = convert_money(self.price, currency_code) except MissingRate: - logger.warning(f"No currency conversion rate available for {self.price_currency} -> {currency_code}") + logger.warning("No currency conversion rate available for %s -> %s", self.price_currency, currency_code) return self.price.amount return converted.amount diff --git a/InvenTree/common/notifications.py b/InvenTree/common/notifications.py index 7e0124da1a..9678d7affb 100644 --- a/InvenTree/common/notifications.py +++ b/InvenTree/common/notifications.py @@ -196,7 +196,7 @@ class MethodStorageClass: filtered_list[ref] = item storage.liste = list(filtered_list.values()) - logger.info(f'Found {len(storage.liste)} notification methods') + logger.info('Found %s notification methods', len(storage.liste)) def get_usersettings(self, user) -> list: """Returns all user settings for a specific user. @@ -339,10 +339,10 @@ def trigger_notification(obj, category=None, obj_ref='pk', **kwargs): delta = timedelta(days=1) if common.models.NotificationEntry.check_recent(category, obj_ref_value, delta): - logger.info(f"Notification '{category}' has recently been sent for '{str(obj)}' - SKIPPING") + logger.info("Notification '%s' has recently been sent for '%s' - SKIPPING", category, str(obj)) return - logger.info(f"Gathering users for notification '{category}'") + logger.info("Gathering users for notification '%s'", category) if target_exclude is None: target_exclude = set() @@ -376,10 +376,10 @@ def trigger_notification(obj, category=None, obj_ref='pk', **kwargs): target_users.add(user) # Unhandled type else: - logger.error(f"Unknown target passed to trigger_notification method: {target}") + logger.error("Unknown target passed to trigger_notification method: %s", target) if target_users: - logger.info(f"Sending notification '{category}' for '{str(obj)}'") + logger.info("Sending notification '%s' for '%s'", category, str(obj)) # Collect possible methods if delivery_methods is None: @@ -388,19 +388,19 @@ def trigger_notification(obj, category=None, obj_ref='pk', **kwargs): delivery_methods = (delivery_methods - IGNORED_NOTIFICATION_CLS) for method in delivery_methods: - logger.info(f"Triggering notification method '{method.METHOD_NAME}'") + logger.info("Triggering notification method '%s'", method.METHOD_NAME) try: deliver_notification(method, obj, category, target_users, context) except NotImplementedError as error: # Allow any single notification method to fail, without failing the others - logger.error(error) + logger.error(error) # noqa: LOG005 except Exception as error: - logger.error(error) + logger.error(error) # noqa: LOG005 # Set delivery flag common.models.NotificationEntry.notify(category, obj_ref_value) else: - logger.info(f"No possible users for notification '{category}'") + logger.info("No possible users for notification '%s'", category) def trigger_superuser_notification(plugin: PluginConfig, msg: str): @@ -440,7 +440,7 @@ def deliver_notification(cls: NotificationMethod, obj, category: str, targets, c if method.targets and len(method.targets) > 0: # Log start - logger.info(f"Notify users via '{method.METHOD_NAME}' for notification '{category}' for '{str(obj)}'") + logger.info("Notify users via '%s' for notification '%s' for '%s'", method.METHOD_NAME, category, str(obj)) # Run setup for delivery method method.setup() @@ -465,6 +465,6 @@ def deliver_notification(cls: NotificationMethod, obj, category: str, targets, c method.cleanup() # Log results - logger.info(f"Notified {success_count} users via '{method.METHOD_NAME}' for notification '{category}' for '{str(obj)}' successfully") + logger.info("Notified %s users via '%s' for notification '%s' for '%s' successfully", success_count, method.METHOD_NAME, category, str(obj)) if not success: logger.info("There were some problems") diff --git a/InvenTree/common/tasks.py b/InvenTree/common/tasks.py index 9a91d99b6e..1725dce0ce 100644 --- a/InvenTree/common/tasks.py +++ b/InvenTree/common/tasks.py @@ -93,7 +93,7 @@ def delete_old_notes_images(): # Remove any notes which point to non-existent image files for note in NotesImage.objects.all(): if not os.path.exists(note.image.path): - logger.info(f"Deleting note {note.image.path} - image file does not exist") + logger.info("Deleting note %s - image file does not exist", note.image.path) note.delete() note_classes = getModelsWithMixin(InvenTreeNotesMixin) @@ -112,7 +112,7 @@ def delete_old_notes_images(): break if not found: - logger.info(f"Deleting note {img} - image file not linked to a note") + logger.info("Deleting note %s - image file not linked to a note", img) note.delete() # Finally, remove any images in the notes dir which are not linked to a note @@ -136,5 +136,5 @@ def delete_old_notes_images(): break if not found: - logger.info(f"Deleting note {image} - image file not linked to a note") + logger.info("Deleting note %s - image file not linked to a note", image) os.remove(os.path.join(notes_dir, image)) diff --git a/InvenTree/label/apps.py b/InvenTree/label/apps.py index cdba5bfc0e..2195419ee8 100644 --- a/InvenTree/label/apps.py +++ b/InvenTree/label/apps.py @@ -141,7 +141,7 @@ class LabelConfig(AppConfig): ) if not dst_dir.exists(): - logger.info(f"Creating required directory: '{dst_dir}'") + logger.info("Creating required directory: '%s'", dst_dir) dst_dir.mkdir(parents=True, exist_ok=True) # Create labels @@ -166,15 +166,15 @@ class LabelConfig(AppConfig): # File already exists - let's see if it is the "same" if hashFile(dst_file) != hashFile(src_file): # pragma: no cover - logger.info(f"Hash differs for '{filename}'") + logger.info("Hash differs for '%s'", filename) to_copy = True else: - logger.info(f"Label template '{filename}' is not present") + logger.info("Label template '%s' is not present", filename) to_copy = True if to_copy: - logger.info(f"Copying label template '{dst_file}'") + logger.info("Copying label template '%s'", dst_file) # Ensure destination dir exists dst_file.parent.mkdir(parents=True, exist_ok=True) @@ -188,7 +188,7 @@ class LabelConfig(AppConfig): except Exception: logger.error(f"Failed to query label for '{filename}' - you should run 'invoke update' first!") - logger.info(f"Creating entry for {model} '{label['name']}'") + logger.info("Creating entry for %s '%s'", model, label['name']) try: model.objects.create( @@ -201,4 +201,4 @@ class LabelConfig(AppConfig): height=label['height'], ) except Exception: - logger.warning(f"Failed to create label '{label['name']}'") + logger.warning("Failed to create label '%s'", label['name']) diff --git a/InvenTree/order/models.py b/InvenTree/order/models.py index 6aa3fa98e0..16ac01aa34 100644 --- a/InvenTree/order/models.py +++ b/InvenTree/order/models.py @@ -135,7 +135,7 @@ class TotalPriceMixin(models.Model): kind, info, data = sys.exc_info() log_error('order.calculate_total_price') - logger.error(f"Missing exchange rate for '{target_currency}'") + logger.exception("Missing exchange rate for '%s'", target_currency) # Return None to indicate the calculated price is invalid return None @@ -152,7 +152,7 @@ class TotalPriceMixin(models.Model): # Record the error, try to press on log_error('order.calculate_total_price') - logger.error(f"Missing exchange rate for '{target_currency}'") + logger.exception("Missing exchange rate for '%s'", target_currency) # Return None to indicate the calculated price is invalid return None diff --git a/InvenTree/part/apps.py b/InvenTree/part/apps.py index 06deb7d60d..f1d512cbc2 100644 --- a/InvenTree/part/apps.py +++ b/InvenTree/part/apps.py @@ -36,7 +36,7 @@ class PartConfig(AppConfig): items = BomItem.objects.filter(part__trackable=False, sub_part__trackable=True) for item in items: - logger.info(f"Marking part '{item.part.name}' as trackable") + logger.info("Marking part '%s' as trackable", item.part.name) item.part.trackable = True item.part.clean() item.part.save() diff --git a/InvenTree/part/models.py b/InvenTree/part/models.py index 797d96f2e4..4527d0c078 100644 --- a/InvenTree/part/models.py +++ b/InvenTree/part/models.py @@ -465,7 +465,7 @@ class Part(InvenTreeBarcodeMixin, InvenTreeNotesMixin, MetadataMixin, MPTTModel) n_refs = Part.objects.filter(image=previous.image).exclude(pk=self.pk).count() if n_refs == 0: - logger.info(f"Deleting unused image file '{previous.image}'") + logger.info("Deleting unused image file '%s'", previous.image) previous.image.delete(save=False) except Part.DoesNotExist: pass @@ -748,7 +748,7 @@ class Part(InvenTreeBarcodeMixin, InvenTreeNotesMixin, MetadataMixin, MPTTModel) except Exception as attr_err: - logger.warning(f"exception while trying to create full name for part {self.name}", attr_err) + logger.warning("exception while trying to create full name for part %s: %s", self.name, attr_err) # Fallback to default format elements = [] @@ -1858,7 +1858,7 @@ class Part(InvenTreeBarcodeMixin, InvenTreeNotesMixin, MetadataMixin, MPTTModel) for item in self.get_bom_items().select_related('sub_part'): if item.sub_part.pk == self.pk: - logger.warning(f"WARNING: BomItem ID {item.pk} contains itself in BOM") + logger.warning("WARNING: BomItem ID %s contains itself in BOM", item.pk) continue q = decimal.Decimal(quantity) @@ -2373,7 +2373,7 @@ class PartPricing(common.models.MetaMixin): try: result = convert_money(money, target_currency) except MissingRate: - logger.warning(f"No currency conversion rate available for {money.currency} -> {target_currency}") + logger.warning("No currency conversion rate available for %s -> %s", money.currency, target_currency) result = None return result @@ -2404,7 +2404,7 @@ class PartPricing(common.models.MetaMixin): self.refresh_from_db() except (PartPricing.DoesNotExist, IntegrityError): # Error thrown if this PartPricing instance has already been removed - logger.warning(f"Error refreshing PartPricing instance for part '{self.part}'") + logger.warning("Error refreshing PartPricing instance for part '%s'", self.part) return # Ensure that the referenced part still exists in the database @@ -2412,12 +2412,12 @@ class PartPricing(common.models.MetaMixin): p = self.part p.refresh_from_db() except IntegrityError: - logger.error(f"Could not update PartPricing as Part '{self.part}' does not exist") + logger.exception("Could not update PartPricing as Part '%s' does not exist", self.part) return if self.scheduled_for_update: # Ignore if the pricing is already scheduled to be updated - logger.debug(f"Pricing for {p} already scheduled for update - skipping") + logger.debug("Pricing for %s already scheduled for update - skipping", p) return if counter > 25: @@ -2430,7 +2430,7 @@ class PartPricing(common.models.MetaMixin): self.save() except IntegrityError: # An IntegrityError here likely indicates that the referenced part has already been deleted - logger.error(f"Could not save PartPricing for part '{self.part}' to the database") + logger.exception("Could not save PartPricing for part '%s' to the database", self.part) return import part.tasks as part_tasks diff --git a/InvenTree/part/serializers.py b/InvenTree/part/serializers.py index e6bcb6cb8c..e3b2876eeb 100644 --- a/InvenTree/part/serializers.py +++ b/InvenTree/part/serializers.py @@ -809,7 +809,7 @@ class PartSerializer(InvenTree.serializers.RemoteImageMixin, InvenTree.serialize save=True ) except IntegrityError: - logger.error(f"Could not create new PartParameter for part {instance}") + logger.exception("Could not create new PartParameter for part %s", instance) # Create initial stock entry if initial_stock: diff --git a/InvenTree/part/stocktake.py b/InvenTree/part/stocktake.py index 52195f68ba..aae3b94f17 100644 --- a/InvenTree/part/stocktake.py +++ b/InvenTree/part/stocktake.py @@ -61,7 +61,7 @@ def perform_stocktake(target: part.models.Part, user: User, note: str = '', comm if not pricing.is_valid: # If pricing is not valid, let's update - logger.info(f"Pricing not valid for {target} - updating") + logger.info("Pricing not valid for %s - updating", target) pricing.update_pricing(cascade=False) pricing.refresh_from_db() @@ -209,7 +209,7 @@ def generate_stocktake_report(**kwargs): logger.info("No parts selected for stocktake report - exiting") return - logger.info(f"Generating new stocktake report for {n_parts} parts") + logger.info("Generating new stocktake report for %s parts", n_parts) base_currency = common.settings.currency_code_default() @@ -309,4 +309,4 @@ def generate_stocktake_report(**kwargs): ) t_stocktake = time.time() - t_start - logger.info(f"Generated stocktake report for {total_parts} parts in {round(t_stocktake, 2)}s") + logger.info("Generated stocktake report for %s parts in %ss", total_parts, round(t_stocktake, 2)) diff --git a/InvenTree/part/tasks.py b/InvenTree/part/tasks.py index 7bafaab2fd..a4ea07ee72 100644 --- a/InvenTree/part/tasks.py +++ b/InvenTree/part/tasks.py @@ -75,7 +75,7 @@ def update_part_pricing(pricing: part.models.PartPricing, counter: int = 0): counter: How many times this function has been called in sequence """ - logger.info(f"Updating part pricing for {pricing.part}") + logger.info("Updating part pricing for %s", pricing.part) pricing.update_pricing(counter=counter) @@ -96,7 +96,7 @@ def check_missing_pricing(limit=250): results = part.models.PartPricing.objects.filter(updated=None)[:limit] if results.count() > 0: - logger.info(f"Found {results.count()} parts with empty pricing") + logger.info("Found %s parts with empty pricing", results.count()) for pp in results: pp.schedule_for_update() @@ -108,7 +108,7 @@ def check_missing_pricing(limit=250): results = part.models.PartPricing.objects.filter(updated__lte=stale_date)[:limit] if results.count() > 0: - logger.info(f"Found {results.count()} stale pricing entries") + logger.info("Found %s stale pricing entries", results.count()) for pp in results: pp.schedule_for_update() @@ -118,7 +118,7 @@ def check_missing_pricing(limit=250): results = part.models.PartPricing.objects.exclude(currency=currency) if results.count() > 0: - logger.info(f"Found {results.count()} pricing entries in the wrong currency") + logger.info("Found %s pricing entries in the wrong currency", results.count()) for pp in results: pp.schedule_for_update() @@ -127,7 +127,7 @@ def check_missing_pricing(limit=250): results = part.models.Part.objects.filter(pricing_data=None)[:limit] if results.count() > 0: - logger.info(f"Found {results.count()} parts without pricing") + logger.info("Found %s parts without pricing", results.count()) for p in results: pricing = p.pricing @@ -154,7 +154,7 @@ def scheduled_stocktake_reports(): old_reports = part.models.PartStocktakeReport.objects.filter(date__lt=threshold) if old_reports.count() > 0: - logger.info(f"Deleting {old_reports.count()} stale stocktake reports") + logger.info("Deleting %s stale stocktake reports", old_reports.count()) old_reports.delete() # Next, check if stocktake functionality is enabled @@ -206,7 +206,7 @@ def rebuild_parameters(template_id): n += 1 if n > 0: - logger.info(f"Rebuilt {n} parameters for template '{template.name}'") + logger.info("Rebuilt %s parameters for template '%s'", n, template.name) def rebuild_supplier_parts(part_id): @@ -234,4 +234,4 @@ def rebuild_supplier_parts(part_id): pass if n > 0: - logger.info(f"Rebuilt {n} supplier parts for part '{prt.name}'") + logger.info("Rebuilt %s supplier parts for part '%s'", n, prt.name) diff --git a/InvenTree/part/templatetags/inventree_extras.py b/InvenTree/part/templatetags/inventree_extras.py index b908d59037..1d641d1594 100644 --- a/InvenTree/part/templatetags/inventree_extras.py +++ b/InvenTree/part/templatetags/inventree_extras.py @@ -67,7 +67,7 @@ def render_date(context, date_object): try: date_object = date.fromisoformat(date_object) except ValueError: - logger.warning(f"Tried to convert invalid date string: {date_object}") + logger.warning("Tried to convert invalid date string: %s", date_object) return None # We may have already pre-cached the date format by calling this already! diff --git a/InvenTree/part/templatetags/sso.py b/InvenTree/part/templatetags/sso.py index f018719e52..250a42ea21 100644 --- a/InvenTree/part/templatetags/sso.py +++ b/InvenTree/part/templatetags/sso.py @@ -53,7 +53,7 @@ def sso_check_provider(provider): if allauth.app_settings.SITES_ENABLED: # At least one matching site must be specified if not app.sites.exists(): - logger.error(f"SocialApp {app} has no sites configured") + logger.error("SocialApp %s has no sites configured", app) return False # At this point, we assume that the provider is correctly configured diff --git a/InvenTree/plugin/base/event/events.py b/InvenTree/plugin/base/event/events.py index 96a91fcec0..24eff73153 100644 --- a/InvenTree/plugin/base/event/events.py +++ b/InvenTree/plugin/base/event/events.py @@ -32,10 +32,10 @@ def trigger_event(event, *args, **kwargs): # Make sure the database can be accessed and is not being tested rn if not canAppAccessDatabase(allow_shell=True) and not settings.PLUGIN_TESTING_EVENTS: - logger.debug(f"Ignoring triggered event '{event}' - database not ready") + logger.debug("Ignoring triggered event '%s' - database not ready", event) return - logger.debug(f"Event triggered: '{event}'") + logger.debug("Event triggered: '%s'", event) # By default, force the event to be processed asynchronously if 'force_async' not in kwargs and not settings.PLUGIN_TESTING_EVENTS: @@ -57,7 +57,7 @@ def register_event(event, *args, **kwargs): """ from common.models import InvenTreeSetting - logger.debug(f"Registering triggered event: '{event}'") + logger.debug("Registering triggered event: '%s'", event) # Determine if there are any plugins which are interested in responding if settings.PLUGIN_TESTING or InvenTreeSetting.get_setting('ENABLE_PLUGINS_EVENTS'): @@ -71,7 +71,7 @@ def register_event(event, *args, **kwargs): if plugin.is_active(): # Only allow event registering for 'active' plugins - logger.debug(f"Registering callback for plugin '{slug}'") + logger.debug("Registering callback for plugin '%s'", slug) # This task *must* be processed by the background worker, # unless we are running CI tests @@ -98,11 +98,11 @@ def process_event(plugin_slug, event, *args, **kwargs): plugin = registry.plugins.get(plugin_slug, None) if plugin is None: # pragma: no cover - logger.error(f"Could not find matching plugin for '{plugin_slug}'") + logger.error("Could not find matching plugin for '%s'", plugin_slug) return plugin.process_event(event, *args, **kwargs) - logger.debug(f"Plugin '{plugin_slug}' is processing triggered event '{event}'") + logger.debug("Plugin '%s' is processing triggered event '%s'", plugin_slug, event) def allow_table_event(table_name): diff --git a/InvenTree/plugin/base/integration/AppMixin.py b/InvenTree/plugin/base/integration/AppMixin.py index 8c3ae557eb..700f94a98e 100644 --- a/InvenTree/plugin/base/integration/AppMixin.py +++ b/InvenTree/plugin/base/integration/AppMixin.py @@ -93,7 +93,7 @@ class AppMixin: models += [model._meta.model_name] except LookupError: # pragma: no cover # if an error occurs the app was never loaded right -> so nothing to do anymore - logger.debug(f'{app_name} App was not found during deregistering') + logger.debug('%s App was not found during deregistering', app_name) break # unregister the models (yes, models are just kept in multilevel dicts) @@ -130,7 +130,7 @@ class AppMixin: app_config = apps.get_app_config(app_name) except LookupError: # pragma: no cover # the plugin was never loaded correctly - logger.debug(f'{app_name} App was not found during deregistering') + logger.debug('%s App was not found during deregistering', app_name) break # reload models if they were set diff --git a/InvenTree/plugin/base/integration/ScheduleMixin.py b/InvenTree/plugin/base/integration/ScheduleMixin.py index 29ece250b2..005b4cedb2 100644 --- a/InvenTree/plugin/base/integration/ScheduleMixin.py +++ b/InvenTree/plugin/base/integration/ScheduleMixin.py @@ -76,7 +76,7 @@ class ScheduleMixin: task_keys += plugin.get_task_names() if len(task_keys) > 0: - logger.info(f"Activated {len(task_keys)} scheduled tasks") + logger.info("Activated %s scheduled tasks", len(task_keys)) # Remove any scheduled tasks which do not match # This stops 'old' plugin tasks from accumulating @@ -93,7 +93,7 @@ class ScheduleMixin: deleted_count += 1 if deleted_count > 0: - logger.info(f"Removed {deleted_count} old scheduled tasks") # pragma: no cover + logger.info("Removed %s old scheduled tasks", deleted_count) # pragma: no cover except (ProgrammingError, OperationalError): # Database might not yet be ready logger.warning("activate_integration_schedule failed, database not ready") @@ -172,13 +172,13 @@ class ScheduleMixin: if Schedule.objects.filter(name=task_name).exists(): # Scheduled task already exists - update it! - logger.info(f"Updating scheduled task '{task_name}'") + logger.info("Updating scheduled task '%s'", task_name) instance = Schedule.objects.get(name=task_name) for item in obj: setattr(instance, item, obj[item]) instance.save() else: - logger.info(f"Adding scheduled task '{task_name}'") + logger.info("Adding scheduled task '%s'", task_name) # Create a new scheduled task Schedule.objects.create(**obj) diff --git a/InvenTree/plugin/base/integration/SettingsMixin.py b/InvenTree/plugin/base/integration/SettingsMixin.py index 42427e7337..609f86925a 100644 --- a/InvenTree/plugin/base/integration/SettingsMixin.py +++ b/InvenTree/plugin/base/integration/SettingsMixin.py @@ -80,7 +80,7 @@ class SettingsMixin: if not plugin: # pragma: no cover # Cannot find associated plugin model, return - logger.error(f"Plugin configuration not found for plugin '{self.slug}'") + logger.error("Plugin configuration not found for plugin '%s'", self.slug) return PluginSetting.set_setting(key, value, user, plugin=plugin) diff --git a/InvenTree/plugin/base/integration/mixins.py b/InvenTree/plugin/base/integration/mixins.py index c969d65f61..f81815f6de 100644 --- a/InvenTree/plugin/base/integration/mixins.py +++ b/InvenTree/plugin/base/integration/mixins.py @@ -492,7 +492,7 @@ class PanelMixin: required_keys = ['title', 'content'] if any(key not in panel for key in required_keys): - logger.warning(f"Custom panel for plugin {__class__} is missing a required parameter") + logger.warning("Custom panel for plugin %s is missing a required parameter", __class__) continue # Add some information on this plugin diff --git a/InvenTree/plugin/base/label/label.py b/InvenTree/plugin/base/label/label.py index 542cc60fa6..ea4d831cc4 100644 --- a/InvenTree/plugin/base/label/label.py +++ b/InvenTree/plugin/base/label/label.py @@ -24,12 +24,12 @@ def print_label(plugin_slug: str, **kwargs): kwargs: passed through to the plugin.print_label() method """ - logger.info(f"Plugin '{plugin_slug}' is printing a label") + logger.info("Plugin '%s' is printing a label", plugin_slug) plugin = registry.get_plugin(plugin_slug) if plugin is None: # pragma: no cover - logger.error(f"Could not find matching plugin for '{plugin_slug}'") + logger.error("Could not find matching plugin for '%s'", plugin_slug) return try: @@ -46,7 +46,7 @@ def print_label(plugin_slug: str, **kwargs): if user: # Log an error message to the database log_error('plugin.print_label') - logger.error(f"Label printing failed: Sending notification to user '{user}'") # pragma: no cover + logger.exception("Label printing failed: Sending notification to user '%s'", user) # pragma: no cover # Throw an error against the plugin instance common.notifications.trigger_notification( diff --git a/InvenTree/plugin/base/locate/mixins.py b/InvenTree/plugin/base/locate/mixins.py index 02b7143aea..e6404af9c3 100644 --- a/InvenTree/plugin/base/locate/mixins.py +++ b/InvenTree/plugin/base/locate/mixins.py @@ -45,7 +45,7 @@ class LocateMixin: Note: A custom implementation could always change this behaviour """ - logger.info(f"LocateMixin: Attempting to locate StockItem pk={item_pk}") + logger.info("LocateMixin: Attempting to locate StockItem pk=%s", item_pk) from stock.models import StockItem diff --git a/InvenTree/plugin/helpers.py b/InvenTree/plugin/helpers.py index 40b97aab9a..d85231d72a 100644 --- a/InvenTree/plugin/helpers.py +++ b/InvenTree/plugin/helpers.py @@ -209,7 +209,7 @@ def render_template(plugin, template_file, context=None): try: tmp = template.loader.get_template(template_file) except template.TemplateDoesNotExist: - logger.error(f"Plugin {plugin.slug} could not locate template '{template_file}'") + logger.exception("Plugin %s could not locate template '%s'", plugin.slug, template_file) return f"""
diff --git a/InvenTree/plugin/registry.py b/InvenTree/plugin/registry.py index 999765edb8..015d217045 100644 --- a/InvenTree/plugin/registry.py +++ b/InvenTree/plugin/registry.py @@ -69,7 +69,7 @@ class PluginsRegistry: def get_plugin(self, slug): """Lookup plugin by slug (unique key).""" if slug not in self.plugins: - logger.warning(f"Plugin registry has no record of plugin '{slug}'") + logger.warning("Plugin registry has no record of plugin '%s'", slug) return None return self.plugins[slug] @@ -82,7 +82,7 @@ class PluginsRegistry: state (bool): Plugin state - true = active, false = inactive """ if slug not in self.plugins_full: - logger.warning(f"Plugin registry has no record of plugin '{slug}'") + logger.warning("Plugin registry has no record of plugin '%s'", slug) return plugin = self.plugins_full[slug].db @@ -137,7 +137,7 @@ class PluginsRegistry: logger.info('Database not accessible while loading plugins') break except IntegrationPluginError as error: - logger.error(f'[PLUGIN] Encountered an error with {error.path}:\n{error.message}') + 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 @@ -254,7 +254,7 @@ class PluginsRegistry: try: pd.mkdir(exist_ok=True) except Exception: # pragma: no cover - logger.error(f"Could not create plugin directory '{pd}'") + logger.exception("Could not create plugin directory '%s'", pd) continue # Ensure the directory has an __init__.py file @@ -264,7 +264,7 @@ class PluginsRegistry: try: init_filename.write_text("# InvenTree plugin directory\n") except Exception: # pragma: no cover - logger.error(f"Could not create file '{init_filename}'") + logger.exception("Could not create file '%s'", init_filename) continue # By this point, we have confirmed that the directory at least exists @@ -277,7 +277,7 @@ class PluginsRegistry: # Add path dirs.append(pd_path) - logger.info(f"Added plugin directory: '{pd}' as '{pd_path}'") + logger.info("Added plugin directory: '%s' as '%s'", pd, pd_path) return dirs @@ -289,7 +289,7 @@ class PluginsRegistry: # Collect plugins from paths for plugin in self.plugin_dirs(): - logger.debug(f"Loading plugins from directory '{plugin}'") + logger.debug("Loading plugins from directory '%s'", plugin) parent_path = None parent_obj = Path(plugin) @@ -326,7 +326,7 @@ class PluginsRegistry: handle_error(error, do_raise=False, log_name='discovery') # Log collected plugins - logger.info(f'Collected {len(collected_plugins)} plugins') + logger.info('Collected %s plugins', len(collected_plugins)) logger.debug(", ".join([a.__module__ for a in collected_plugins])) return collected_plugins @@ -349,7 +349,7 @@ class PluginsRegistry: try: subprocess.check_output(['pip', 'install', '-U', '-r', settings.PLUGIN_FILE], cwd=settings.BASE_DIR.parent) except subprocess.CalledProcessError as error: # pragma: no cover - logger.error(f'Ran into error while trying to install plugins!\n{str(error)}') + logger.exception('Ran into error while trying to install plugins!\n%s', str(error)) return False except FileNotFoundError: # pragma: no cover # System most likely does not have 'git' installed @@ -427,7 +427,7 @@ class PluginsRegistry: raise error # pragma: no cover plg_db = None except (IntegrityError) as error: # pragma: no cover - logger.error(f"Error initializing plugin `{plg_name}`: {error}") + logger.exception("Error initializing plugin `%s`: %s", plg_name, error) handle_error(error, log_name='init') # Append reference to plugin @@ -452,16 +452,16 @@ class PluginsRegistry: continue # continue -> the plugin is not loaded # Initialize package - we can be sure that an admin has activated the plugin - logger.debug(f'Loading plugin `{plg_name}`') + logger.debug('Loading plugin `%s`', plg_name) try: t_start = time.time() plg_i: InvenTreePlugin = plg() dt = time.time() - t_start - logger.info(f'Loaded plugin `{plg_name}` in {dt:.3f}s') + logger.info('Loaded plugin `%s` in {%.3f}s', plg_name, dt) except Exception as error: handle_error(error, log_name='init') # log error and raise it -> disable plugin - logger.warning(f"Plugin `{plg_name}` could not be loaded") + logger.warning("Plugin `%s` could not be loaded", plg_name) # Safe extra attributes plg_i.is_package = getattr(plg_i, 'is_package', False) @@ -510,7 +510,7 @@ class PluginsRegistry: # Activate integrations plugins = self.plugins.items() - logger.info(f'Found {len(plugins)} active plugins') + logger.info('Found %s active plugins', len(plugins)) for mixin in self.__get_mixin_order(): if hasattr(mixin, '_activate_mixin'): diff --git a/InvenTree/plugin/samples/event/event_sample.py b/InvenTree/plugin/samples/event/event_sample.py index f6638cb480..2ae21dcbb5 100644 --- a/InvenTree/plugin/samples/event/event_sample.py +++ b/InvenTree/plugin/samples/event/event_sample.py @@ -25,4 +25,4 @@ class EventPluginSample(EventMixin, InvenTreePlugin): # Issue warning that we can test for if settings.PLUGIN_TESTING: - logger.debug(f'Event `{event}` triggered in sample plugin') + logger.debug('Event `%s` triggered in sample plugin', event) diff --git a/InvenTree/plugin/samples/locate/locate_sample.py b/InvenTree/plugin/samples/locate/locate_sample.py index 7cf63e2bf2..13c7f4e304 100644 --- a/InvenTree/plugin/samples/locate/locate_sample.py +++ b/InvenTree/plugin/samples/locate/locate_sample.py @@ -31,17 +31,17 @@ class SampleLocatePlugin(LocateMixin, InvenTreePlugin): """ from stock.models import StockItem - logger.info(f"SampleLocatePlugin attempting to locate item ID {item_pk}") + logger.info("SampleLocatePlugin attempting to locate item ID %s", item_pk) try: item = StockItem.objects.get(pk=item_pk) - logger.info(f"StockItem {item_pk} located!") + logger.info("StockItem %s located!", item_pk) # Tag metadata item.set_metadata('located', True) except (ValueError, StockItem.DoesNotExist): # pragma: no cover - logger.error(f"StockItem ID {item_pk} does not exist!") + logger.exception("StockItem ID %s does not exist!", item_pk) def locate_stock_location(self, location_pk): """Locate a StockLocation. @@ -51,14 +51,14 @@ class SampleLocatePlugin(LocateMixin, InvenTreePlugin): """ from stock.models import StockLocation - logger.info(f"SampleLocatePlugin attempting to locate location ID {location_pk}") + logger.info("SampleLocatePlugin attempting to locate location ID %s", location_pk) try: location = StockLocation.objects.get(pk=location_pk) - logger.info(f"Location exists at '{location.pathstring}'") + logger.info("Location exists at '%s'", location.pathstring) # Tag metadata location.set_metadata('located', True) except (ValueError, StockLocation.DoesNotExist): # pragma: no cover - logger.error(f"Location ID {location_pk} does not exist!") + logger.exception("Location ID %s does not exist!", location_pk) diff --git a/InvenTree/plugin/views.py b/InvenTree/plugin/views.py index 2073f25422..49a772f401 100644 --- a/InvenTree/plugin/views.py +++ b/InvenTree/plugin/views.py @@ -27,7 +27,7 @@ class InvenTreePluginViewMixin: except Exception: # Log the error to the database log_error(self.request.path) - logger.error(f"Plugin '{plug.slug}' could not render custom panels at '{self.request.path}'") + logger.exception("Plugin '%s' could not render custom panels at '%s'", plug.slug, self.request.path) return panels diff --git a/InvenTree/report/apps.py b/InvenTree/report/apps.py index 7c64c8609c..df948fcc47 100644 --- a/InvenTree/report/apps.py +++ b/InvenTree/report/apps.py @@ -55,7 +55,7 @@ class ReportConfig(AppConfig): ) if not dst_dir.exists(): - logger.info(f"Creating missing directory: '{dst_dir}'") + logger.info("Creating missing directory: '%s'", dst_dir) dst_dir.mkdir(parents=True, exist_ok=True) # Copy each report template across (if required) @@ -73,7 +73,7 @@ class ReportConfig(AppConfig): dst_file = settings.MEDIA_ROOT.joinpath(filename) if not dst_file.exists(): - logger.info(f"Copying test report template '{dst_file}'") + logger.info("Copying test report template '%s'", dst_file) shutil.copyfile(src_file, dst_file) try: @@ -81,7 +81,7 @@ class ReportConfig(AppConfig): if model.objects.filter(template=filename).exists(): continue - logger.info(f"Creating new TestReport for '{report['name']}'") + logger.info("Creating new TestReport for '%s'", report.get('name')) model.objects.create( name=report['name'], diff --git a/InvenTree/report/models.py b/InvenTree/report/models.py index 2104b73476..66810490f7 100644 --- a/InvenTree/report/models.py +++ b/InvenTree/report/models.py @@ -130,7 +130,7 @@ class ReportBase(models.Model): if str(filename) == str(self.template): if fullpath.exists(): - logger.info(f"Deleting existing report template: '{filename}'") + logger.info("Deleting existing report template: '%s'", filename) os.remove(fullpath) # Ensure that the cache is cleared for this template! @@ -555,7 +555,7 @@ def rename_snippet(instance, filename): if str(filename) == str(instance.snippet): if fullpath.exists(): - logger.info(f"Deleting existing snippet file: '{filename}'") + logger.info("Deleting existing snippet file: '%s'", filename) os.remove(fullpath) # Ensure that the cache is deleted for this snippet @@ -593,7 +593,7 @@ def rename_asset(instance, filename): fullpath = settings.MEDIA_ROOT.joinpath(path).resolve() if fullpath.exists(): - logger.info(f"Deleting existing asset file: '{filename}'") + logger.info("Deleting existing asset file: '%s'", filename) os.remove(fullpath) return path diff --git a/InvenTree/report/templatetags/report.py b/InvenTree/report/templatetags/report.py index cb8c8f2105..1d6775521f 100644 --- a/InvenTree/report/templatetags/report.py +++ b/InvenTree/report/templatetags/report.py @@ -129,7 +129,7 @@ def uploaded_image(filename, replace_missing=True, replacement_file='blank_image exists = False if exists and validate and not InvenTree.helpers.TestIfImage(full_path): - logger.warning(f"File '{filename}' is not a valid image") + logger.warning("File '%s' is not a valid image", filename) exists = False if not exists and not replace_missing: diff --git a/InvenTree/users/apps.py b/InvenTree/users/apps.py index ccaa57c1dc..1f6e503fc6 100644 --- a/InvenTree/users/apps.py +++ b/InvenTree/users/apps.py @@ -44,7 +44,7 @@ class UsersConfig(AppConfig): # First, delete any rule_set objects which have become outdated! for rule in RuleSet.objects.all(): if rule.name not in RuleSet.RULESET_NAMES: # pragma: no cover # can not change ORM without the app being loaded - logger.info(f"Deleting outdated ruleset: {rule.name}") + logger.info("Deleting outdated ruleset: %s", rule.name) rule.delete() # Update group permission assignments for all groups diff --git a/InvenTree/users/models.py b/InvenTree/users/models.py index 488b9d4c93..e224fbc4ef 100644 --- a/InvenTree/users/models.py +++ b/InvenTree/users/models.py @@ -286,7 +286,7 @@ class RuleSet(models.Model): # Print message instead of throwing an error name = getattr(user, 'name', user.pk) - logger.debug(f"User '{name}' failed permission check for {table}.{permission}") + logger.debug("User '%s' failed permission check for %s.%s", name, table, permission) return False @@ -457,7 +457,7 @@ def update_group_roles(group, debug=False): content_type = ContentType.objects.get(app_label=app, model=model) permission = Permission.objects.get(content_type=content_type, codename=perm) except ContentType.DoesNotExist: # pragma: no cover - logger.warning(f"Error: Could not find permission matching '{permission_string}'") + logger.warning("Error: Could not find permission matching '%s'", permission_string) permission = None return permission @@ -475,7 +475,7 @@ def update_group_roles(group, debug=False): group.permissions.add(permission) if debug: # pragma: no cover - logger.debug(f"Adding permission {perm} to group {group.name}") + logger.debug("Adding permission %s to group %s", perm, group.name) # Remove any extra permissions from the group for perm in permissions_to_delete: @@ -490,7 +490,7 @@ def update_group_roles(group, debug=False): group.permissions.remove(permission) if debug: # pragma: no cover - logger.debug(f"Removing permission {perm} from group {group.name}") + logger.debug("Removing permission %s from group %s", perm, group.name) # Enable all action permissions for certain children models # if parent model has 'change' permission @@ -512,7 +512,7 @@ def update_group_roles(group, debug=False): permission = get_permission_object(child_perm) if permission: group.permissions.add(permission) - logger.debug(f"Adding permission {child_perm} to group {group.name}") + logger.debug("Adding permission %s to group %s", child_perm, group.name) def clear_user_role_cache(user): diff --git a/docker/gunicorn.conf.py b/docker/gunicorn.conf.py index 58b48a0c8d..256bd5c0b7 100644 --- a/docker/gunicorn.conf.py +++ b/docker/gunicorn.conf.py @@ -33,7 +33,7 @@ if workers is not None: if workers is None: workers = multiprocessing.cpu_count() * 2 + 1 -logger.info(f"Starting gunicorn server with {workers} workers") +logger.info("Starting gunicorn server with %s workers", workers) max_requests = 1000 max_requests_jitter = 50