mirror of
https://github.com/inventree/InvenTree
synced 2024-08-30 18:33:04 +00:00
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
This commit is contained in:
parent
08e7190832
commit
71c416bafd
@ -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'
|
||||
|
@ -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
|
||||
|
@ -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
|
||||
|
@ -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
|
||||
|
||||
|
@ -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
|
||||
|
||||
|
@ -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")
|
||||
|
@ -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
|
||||
|
@ -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:
|
||||
|
@ -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
|
||||
|
@ -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)
|
||||
|
@ -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
|
||||
|
@ -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))]
|
||||
|
||||
|
@ -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')
|
||||
|
@ -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')
|
||||
|
@ -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()),
|
||||
|
@ -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
|
||||
|
@ -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")
|
||||
|
@ -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))
|
||||
|
@ -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'])
|
||||
|
@ -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
|
||||
|
@ -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()
|
||||
|
@ -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
|
||||
|
@ -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:
|
||||
|
@ -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))
|
||||
|
@ -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)
|
||||
|
@ -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!
|
||||
|
@ -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
|
||||
|
@ -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):
|
||||
|
@ -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
|
||||
|
@ -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)
|
||||
|
||||
|
@ -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)
|
||||
|
@ -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
|
||||
|
@ -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(
|
||||
|
@ -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
|
||||
|
||||
|
@ -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"""
|
||||
<div class='alert alert-block alert-danger'>
|
||||
|
@ -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'):
|
||||
|
@ -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)
|
||||
|
@ -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)
|
||||
|
@ -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
|
||||
|
||||
|
@ -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'],
|
||||
|
@ -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
|
||||
|
@ -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:
|
||||
|
@ -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
|
||||
|
@ -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):
|
||||
|
@ -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
|
||||
|
Loading…
Reference in New Issue
Block a user