From 530f7c9d6b43bfdec3363d9fd8d5e856d8be7e72 Mon Sep 17 00:00:00 2001 From: Hayden <64056131+hay-kot@users.noreply.github.com> Date: Sat, 28 Jan 2023 16:54:44 -0900 Subject: [PATCH] logging improvements (#2073) * Scheduled tasks log to Debug, not Info * Add LOG_LEVEL config to .env * Update some other log levels and fix typos * fix logger initializer --------- Co-authored-by: Jakob Rubin <647846+Grygon@users.noreply.github.com> --- mealie/core/root_logger.py | 4 ++++ mealie/core/settings/settings.py | 1 + mealie/db/init_db.py | 4 ++-- mealie/services/email/email_senders.py | 2 +- mealie/services/recipe/recipe_data_service.py | 3 +-- mealie/services/recipe/recipe_service.py | 2 +- mealie/services/scheduler/scheduler_registry.py | 14 +++++++------- mealie/services/scheduler/scheduler_service.py | 6 +++--- .../scheduler/tasks/purge_group_exports.py | 4 ++-- .../scheduler/tasks/purge_password_reset.py | 4 ++-- .../services/scheduler/tasks/purge_registration.py | 2 +- .../services/scheduler/tasks/reset_locked_users.py | 4 ++-- mealie/services/scraper/scraper.py | 2 +- 13 files changed, 28 insertions(+), 24 deletions(-) diff --git a/mealie/core/root_logger.py b/mealie/core/root_logger.py index a04d795422d5..29db504fee7c 100644 --- a/mealie/core/root_logger.py +++ b/mealie/core/root_logger.py @@ -27,6 +27,8 @@ class LoggerConfig: def get_logger_config(): settings = get_app_settings() + log_level = logging._nameToLevel[settings.LOG_LEVEL] + if not settings.PRODUCTION: from rich.logging import RichHandler @@ -35,6 +37,7 @@ def get_logger_config(): format=None, date_format=None, logger_file=None, + level=log_level, ) output_file_handler = logging.FileHandler(LOGGER_FILE) @@ -50,6 +53,7 @@ def get_logger_config(): format="%(levelname)s: %(asctime)s \t%(message)s", date_format="%d-%b-%y %H:%M:%S", logger_file=LOGGER_FILE, + level=log_level, ) diff --git a/mealie/core/settings/settings.py b/mealie/core/settings/settings.py index f22e64c350e1..fb60491f9e15 100644 --- a/mealie/core/settings/settings.py +++ b/mealie/core/settings/settings.py @@ -30,6 +30,7 @@ class AppSettings(BaseSettings): API_DOCS: bool = True TOKEN_TIME: int = 48 # Time in Hours SECRET: str + LOG_LEVEL: str = "INFO" # Corresponds to standard Python log levels. GIT_COMMIT_HASH: str = "unknown" diff --git a/mealie/db/init_db.py b/mealie/db/init_db.py index 259bf09a4dcb..461518841059 100644 --- a/mealie/db/init_db.py +++ b/mealie/db/init_db.py @@ -87,7 +87,7 @@ def main(): alembic_cfg = Config(str(PROJECT_DIR / "alembic.ini")) if db_is_at_head(alembic_cfg): - logger.info("Migration not needed.") + logger.debug("Migration not needed.") else: logger.info("Migration needed. Performing migration...") command.upgrade(alembic_cfg, "head") @@ -95,7 +95,7 @@ def main(): db = get_repositories(session) if db.users.get_all(): - logger.info("Database exists") + logger.debug("Database exists") else: logger.info("Database contains no users, initializing...") init_db(db) diff --git a/mealie/services/email/email_senders.py b/mealie/services/email/email_senders.py index 1a77d8839b4c..d4a2e68ec225 100644 --- a/mealie/services/email/email_senders.py +++ b/mealie/services/email/email_senders.py @@ -96,7 +96,7 @@ class DefaultEmailSender(ABCEmailSender, BaseService): smtp_options.password = self.settings.SMTP_PASSWORD response = message.send(to=email_to, smtp=smtp_options) - self.logger.info(f"send email result: {response}") + self.logger.debug(f"send email result: {response}") if not response.success: self.logger.error(f"send email error: {response}") diff --git a/mealie/services/recipe/recipe_data_service.py b/mealie/services/recipe/recipe_data_service.py index 512db9a2ebb3..23e16f99e63e 100644 --- a/mealie/services/recipe/recipe_data_service.py +++ b/mealie/services/recipe/recipe_data_service.py @@ -156,7 +156,6 @@ class RecipeDataService(BaseService): self.logger.error(f"Content-Type: {content_type} is not an image") raise NotAnImageError(f"Content-Type {content_type} is not an image") - self.logger.info(f"File Name Suffix {file_path.suffix}") + self.logger.debug(f"File Name Suffix {file_path.suffix}") self.write_image(r.read(), file_path.suffix) - file_path.unlink(missing_ok=True) diff --git a/mealie/services/recipe/recipe_service.py b/mealie/services/recipe/recipe_service.py index 3df22c399c0b..6882c904fac4 100644 --- a/mealie/services/recipe/recipe_service.py +++ b/mealie/services/recipe/recipe_service.py @@ -63,7 +63,7 @@ class RecipeService(BaseService): try: copytree(current_dir, recipe.directory, dirs_exist_ok=True) - self.logger.info(f"Renaming Recipe Directory: {original_slug} -> {recipe.slug}") + self.logger.debug(f"Renaming Recipe Directory: {original_slug} -> {recipe.slug}") except FileNotFoundError: self.logger.error(f"Recipe Directory not Found: {original_slug}") diff --git a/mealie/services/scheduler/scheduler_registry.py b/mealie/services/scheduler/scheduler_registry.py index 88af59338bf8..9a33518c2515 100644 --- a/mealie/services/scheduler/scheduler_registry.py +++ b/mealie/services/scheduler/scheduler_registry.py @@ -17,7 +17,7 @@ class SchedulerRegistry: @staticmethod def _register(name: str, callbacks: list[Callable], callback: Iterable[Callable]): for cb in callback: - logger.info(f"Registering {name} callback: {cb.__name__}") + logger.debug(f"Registering {name} callback: {cb.__name__}") callbacks.append(cb) @staticmethod @@ -26,7 +26,7 @@ class SchedulerRegistry: @staticmethod def remove_daily(callback: Callable): - logger.info(f"Removing daily callback: {callback.__name__}") + logger.debug(f"Removing daily callback: {callback.__name__}") SchedulerRegistry._daily.remove(callback) @staticmethod @@ -35,7 +35,7 @@ class SchedulerRegistry: @staticmethod def remove_hourly(callback: Callable): - logger.info(f"Removing hourly callback: {callback.__name__}") + logger.debug(f"Removing hourly callback: {callback.__name__}") SchedulerRegistry._hourly.remove(callback) @staticmethod @@ -44,16 +44,16 @@ class SchedulerRegistry: @staticmethod def remove_minutely(callback: Callable): - logger.info(f"Removing minutely callback: {callback.__name__}") + logger.debug(f"Removing minutely callback: {callback.__name__}") SchedulerRegistry._minutely.remove(callback) @staticmethod def print_jobs(): for job in SchedulerRegistry._daily: - logger.info(f"Daily job: {job.__name__}") + logger.debug(f"Daily job: {job.__name__}") for job in SchedulerRegistry._hourly: - logger.info(f"Hourly job: {job.__name__}") + logger.debug(f"Hourly job: {job.__name__}") for job in SchedulerRegistry._minutely: - logger.info(f"Minutely job: {job.__name__}") + logger.debug(f"Minutely job: {job.__name__}") diff --git a/mealie/services/scheduler/scheduler_service.py b/mealie/services/scheduler/scheduler_service.py index bf9f1ff49e44..8a930bc0637c 100644 --- a/mealie/services/scheduler/scheduler_service.py +++ b/mealie/services/scheduler/scheduler_service.py @@ -31,20 +31,20 @@ def _scheduled_task_wrapper(callable): @repeat_every(minutes=MINUTES_DAY, wait_first=True, logger=logger) def run_daily(): - logger.info("Running daily callbacks") + logger.debug("Running daily callbacks") for func in SchedulerRegistry._daily: _scheduled_task_wrapper(func) @repeat_every(minutes=MINUTES_HOUR, wait_first=True, logger=logger) def run_hourly(): - logger.info("Running hourly callbacks") + logger.debug("Running hourly callbacks") for func in SchedulerRegistry._hourly: _scheduled_task_wrapper(func) @repeat_every(minutes=MINUTES_5, wait_first=True, logger=logger) def run_minutely(): - logger.info("Running minutely callbacks") + logger.debug("Running minutely callbacks") for func in SchedulerRegistry._minutely: _scheduled_task_wrapper(func) diff --git a/mealie/services/scheduler/tasks/purge_group_exports.py b/mealie/services/scheduler/tasks/purge_group_exports.py index 648215f83291..9c5506f84ba4 100644 --- a/mealie/services/scheduler/tasks/purge_group_exports.py +++ b/mealie/services/scheduler/tasks/purge_group_exports.py @@ -13,7 +13,7 @@ def purge_group_data_exports(max_minutes_old=ONE_DAY_AS_MINUTES): """Purges all group exports after x days""" logger = root_logger.get_logger() - logger.info("purging group data exports") + logger.debug("purging group data exports") limit = datetime.datetime.now() - datetime.timedelta(minutes=max_minutes_old) with session_context() as session: @@ -41,6 +41,6 @@ def purge_excess_files() -> None: # TODO: fix comparison types if file.stat().st_mtime < limit: # type: ignore file.unlink() - logger.info(f"excess group file removed '{file}'") + logger.debug(f"excess group file removed '{file}'") logger.info("finished purging excess files") diff --git a/mealie/services/scheduler/tasks/purge_password_reset.py b/mealie/services/scheduler/tasks/purge_password_reset.py index ab8e4808bda5..3326201fb1a1 100644 --- a/mealie/services/scheduler/tasks/purge_password_reset.py +++ b/mealie/services/scheduler/tasks/purge_password_reset.py @@ -11,11 +11,11 @@ MAX_DAYS_OLD = 2 def purge_password_reset_tokens(): """Purges all events after x days""" - logger.info("purging password reset tokens") + logger.debug("purging password reset tokens") limit = datetime.datetime.now() - datetime.timedelta(days=MAX_DAYS_OLD) with session_context() as session: session.query(PasswordResetModel).filter(PasswordResetModel.created_at <= limit).delete() session.commit() session.close() - logger.info("password reset tokens purges") + logger.info("password reset tokens purged") diff --git a/mealie/services/scheduler/tasks/purge_registration.py b/mealie/services/scheduler/tasks/purge_registration.py index 33f9efc78dbc..5409cf87760b 100644 --- a/mealie/services/scheduler/tasks/purge_registration.py +++ b/mealie/services/scheduler/tasks/purge_registration.py @@ -11,7 +11,7 @@ MAX_DAYS_OLD = 4 def purge_group_registration(): """Purges all events after x days""" - logger.info("purging expired registration tokens") + logger.debug("purging expired registration tokens") limit = datetime.datetime.now() - datetime.timedelta(days=MAX_DAYS_OLD) with session_context() as session: diff --git a/mealie/services/scheduler/tasks/reset_locked_users.py b/mealie/services/scheduler/tasks/reset_locked_users.py index 3dd1ab7f82ea..cfd67b8921a5 100644 --- a/mealie/services/scheduler/tasks/reset_locked_users.py +++ b/mealie/services/scheduler/tasks/reset_locked_users.py @@ -6,12 +6,12 @@ from mealie.services.user_services.user_service import UserService def locked_user_reset(): logger = root_logger.get_logger() - logger.info("resetting locked users") + logger.debug("resetting locked users") with session_context() as session: repos = AllRepositories(session) user_service = UserService(repos) unlocked = user_service.reset_locked_users() - logger.info(f"scheduled task unlocked {unlocked} users in the database") + logger.debug(f"scheduled task unlocked {unlocked} users in the database") logger.info("locked users reset") diff --git a/mealie/services/scraper/scraper.py b/mealie/services/scraper/scraper.py index 70ce2fdc67ce..eb8d415b88d5 100644 --- a/mealie/services/scraper/scraper.py +++ b/mealie/services/scraper/scraper.py @@ -37,7 +37,7 @@ async def create_from_url(url: str) -> tuple[Recipe, ScrapedExtras | None]: new_recipe.id = uuid4() logger = get_logger() - logger.info(f"Image {new_recipe.image}") + logger.debug(f"Image {new_recipe.image}") recipe_data_service = RecipeDataService(new_recipe.id)