diff --git a/CHANGES.rst b/CHANGES.rst index 8d71b49..ef8ac72 100644 --- a/CHANGES.rst +++ b/CHANGES.rst @@ -7,6 +7,7 @@ Fixes General ~~~~~~~ +- Overhauled logging system to avoid unnecessary file bloat and I/O. Speed ups of about a factor 3 - Overhauled how config files are read in to avoid unneccesary I/O. Speed ups of about a factor 2 0.0.4 (2024-05-09) diff --git a/pyproject.toml b/pyproject.toml index 9d980da..5e8a994 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -33,6 +33,7 @@ classifiers = [ ] dependencies = [ + "colorlog", "discordwebhook", "numpy", "packaging", diff --git a/romsearch/modules/datparser.py b/romsearch/modules/datparser.py index 566a6c9..fb4c71b 100644 --- a/romsearch/modules/datparser.py +++ b/romsearch/modules/datparser.py @@ -1,13 +1,11 @@ import glob -import json import os -from datetime import datetime from urllib.request import urlopen import xmltodict import romsearch -from ..util import load_yml, setup_logger, create_bar, unzip_file, save_json +from ..util import load_yml, setup_logger, unzip_file, save_json ALLOWED_GROUPS = [ "No-Intro", @@ -44,6 +42,7 @@ def __init__(self, config_file=None, config=None, platform_config=None, + logger=None, ): """Parser for dat files from Redump or No-Intro @@ -56,18 +55,19 @@ def __init__(self, config_file (str, optional): Configuration file. Defaults to None config (dict, optional): Configuration dictionary. Defaults to None platform_config (dict, optional): Platform configuration dictionary. Defaults to None + logger (logging.Logger, optional): Logger instance. Defaults to None """ if platform is None: raise ValueError("platform must be specified") self.platform = platform - logger_add_dir = str(os.path.join(platform)) - - self.logger = setup_logger(log_level="info", - script_name=f"DATParser", - additional_dir=logger_add_dir, - ) + if logger is None: + logger = setup_logger(log_level="info", + script_name=f"DATParser", + additional_dir=platform, + ) + self.logger = logger if config_file is None and config is None: raise ValueError("config_file or config must be specified") @@ -108,8 +108,6 @@ def __init__(self, def run(self): - self.logger.info(create_bar(f"START DATParser")) - run_datparser = True if self.dat_dir is None: @@ -125,8 +123,6 @@ def run(self): if run_datparser: self.run_datparser() - self.logger.info(create_bar(f"FINISH DATParser")) - return True def run_datparser(self): @@ -146,6 +142,8 @@ def run_datparser(self): if dat is None: return False + self.logger.info(f"Using dat file {os.path.split(dat_file_name)[-1]}") + rom_dict = format_dat(dat) self.save_rom_dict(rom_dict) diff --git a/romsearch/modules/dupeparser.py b/romsearch/modules/dupeparser.py index d295a6d..7777693 100644 --- a/romsearch/modules/dupeparser.py +++ b/romsearch/modules/dupeparser.py @@ -5,7 +5,6 @@ import romsearch from ..util import (setup_logger, - create_bar, load_yml, get_parent_name, get_short_name, @@ -27,6 +26,7 @@ def __init__(self, config=None, default_config=None, regex_config=None, + logger=None, ): """Tool for figuring out a list of dupes @@ -36,6 +36,7 @@ def __init__(self, config (dict, optional): Configuration dictionary. Defaults to None default_config (dict, optional): Default configuration dictionary. Defaults to None regex_config (dict, optional): Configuration dictionary for regex search. Defaults to None + logger (logging.Logger, optional): Logger instance. Defaults to None TODO: - At some point, we might want to consider adding in the retool supersets @@ -45,12 +46,12 @@ def __init__(self, raise ValueError("platform must be specified") self.platform = platform - logger_add_dir = str(os.path.join(platform)) - - self.logger = setup_logger(log_level="info", - script_name=f"DupeParser", - additional_dir=logger_add_dir, - ) + if logger is None: + logger = setup_logger(log_level="info", + script_name=f"DupeParser", + additional_dir=platform, + ) + self.logger = logger if config_file is None and config is None: raise ValueError("config_file or config must be specified") @@ -95,16 +96,12 @@ def run(self): self.logger.warning("retool config for the platform needs to be present if using retool") return False - self.logger.info(create_bar(f"START DupeParser")) - dupe_dict = self.get_dupe_dict() # Save out the dupe dict out_file = os.path.join(self.dupe_dir, f"{self.platform} (dupes).json") save_json(dupe_dict, out_file) - self.logger.info(create_bar(f"FINISH DupeParser")) - return True def get_dupe_dict(self): @@ -114,10 +111,8 @@ def get_dupe_dict(self): # Prefer retool dupes first if self.use_retool: - self.logger.info("Gettings dupes from retool file") dupe_dict = self.get_retool_dupes(dupe_dict) if self.use_dat: - self.logger.info("Gettings dupes from dat file") dupe_dict = self.get_dat_dupes(dupe_dict) dupe_dict = dict(sorted(dupe_dict.items())) @@ -209,11 +204,6 @@ def get_retool_dupes(self, dupe_dict=None): for f in retool_dupe["titles"]] priorities = [f.get("priority", 1) for f in retool_dupe["titles"]] - # Parse down to the game name here - # if "(" in group: - # group_parsed = get_game_name(group) - # else: - # group_parsed = copy.deepcopy(group) group_parsed = get_short_name(group, default_config=self.default_config, regex_config=self.regex_config, diff --git a/romsearch/modules/gamefinder.py b/romsearch/modules/gamefinder.py index 1c2b870..f637d4b 100644 --- a/romsearch/modules/gamefinder.py +++ b/romsearch/modules/gamefinder.py @@ -5,7 +5,12 @@ import numpy as np import romsearch -from ..util import setup_logger, load_yml, get_parent_name, get_short_name, create_bar, load_json +from ..util import (setup_logger, + load_yml, + get_parent_name, + get_short_name, + load_json + ) def get_all_games(files, @@ -49,6 +54,7 @@ def __init__(self, config=None, default_config=None, regex_config=None, + logger=None, ): """Tool to find games within a list of files @@ -61,12 +67,15 @@ def __init__(self, config (dict, optional): Configuration dictionary. Defaults to None. default_config (dict, optional): Default configuration dictionary. Defaults to None. regex_config (dict, optional): Dictionary of regex config. Defaults to None. + logger (logging.Logger, optional): Logger instance. Defaults to None. """ - self.logger = setup_logger(log_level="info", - script_name=f"GameFinder", - additional_dir=platform, - ) + if logger is None: + logger = setup_logger(log_level="info", + script_name=f"GameFinder", + additional_dir=platform, + ) + self.logger = logger if platform is None: raise ValueError("platform must be specified") @@ -104,14 +113,12 @@ def run(self, files, ): - self.logger.info(create_bar(f"START GameFinder")) - games_dict = self.get_game_dict(files) games_dict = dict(sorted(games_dict.items())) - self.logger.info(f"Found {len(games_dict)} games:") + self.logger.debug(f"Found {len(games_dict)} games:") for g in games_dict: - self.logger.info(f"{g}: {games_dict[g]}") + self.logger.debug(f"{g}: {games_dict[g]}") return games_dict diff --git a/romsearch/modules/romchooser.py b/romsearch/modules/romchooser.py index 94316da..3f0df9f 100644 --- a/romsearch/modules/romchooser.py +++ b/romsearch/modules/romchooser.py @@ -8,7 +8,6 @@ import romsearch from ..util import (setup_logger, - create_bar, load_yml, ) @@ -302,6 +301,7 @@ def __init__(self, config=None, default_config=None, regex_config=None, + logger=None, ): """ROM choose tool @@ -314,18 +314,20 @@ def __init__(self, config (dict, optional): Configuration dictionary. Defaults to None. default_config (dict, optional): Default configuration dictionary. Defaults to None. regex_config (dict, optional): Configuration dictionary. Defaults to None. + logger (logging.Logger, optional): Logger instance. Defaults to None. """ if platform is None: raise ValueError("platform must be specified") self.platform = platform - logger_add_dir = str(os.path.join(platform, game)) - - self.logger = setup_logger(log_level="info", - script_name=f"ROMChooser", - additional_dir=logger_add_dir, - ) + if logger is None: + logger_add_dir = str(os.path.join(platform, game)) + logger = setup_logger(log_level="info", + script_name=f"ROMChooser", + additional_dir=logger_add_dir, + ) + self.logger = logger if config_file is None and config is None: raise ValueError("config_file or config must be specified") @@ -394,12 +396,8 @@ def run(self, rom_dict): """Run the ROM chooser""" - self.logger.info(create_bar(f"START ROMChooser")) - rom_dict = self.run_chooser(rom_dict) - self.logger.info(create_bar(f"FINISH ROMChooser")) - return rom_dict def run_chooser(self, diff --git a/romsearch/modules/romdownloader.py b/romsearch/modules/romdownloader.py index f855e6c..8016715 100644 --- a/romsearch/modules/romdownloader.py +++ b/romsearch/modules/romdownloader.py @@ -5,11 +5,10 @@ import romsearch from ..util import (setup_logger, - create_bar, load_yml, get_file_pattern, discord_push, -split, + split, ) @@ -40,6 +39,7 @@ def add_rclone_filter(pattern=None, return cmd + def get_tidy_files(glob_pattern): """Get a tidy list of files from a glob pattern. @@ -62,6 +62,7 @@ def __init__(self, config_file=None, config=None, platform_config=None, + logger=None, ): """Downloader tool via rclone @@ -72,16 +73,19 @@ def __init__(self, config (str, optional): Configuration file. Defaults to None config (dict, optional): Configuration dictionary. Defaults to None platform_config (dict, optional): Platform configuration dictionary. Defaults to None + logger (logging.Logger, optional): Logger instance. Defaults to None """ if platform is None: raise ValueError("platform must be specified") self.platform = platform - self.logger = setup_logger(log_level="info", - script_name=f"ROMDownloader", - additional_dir=platform, - ) + if logger is None: + logger = setup_logger(log_level="info", + script_name=f"ROMDownloader", + additional_dir=platform, + ) + self.logger = logger if config_file is None and config is None: raise ValueError("config_file or config must be specified") @@ -138,8 +142,6 @@ def run(self, ): """Run Rclone sync tool""" - self.logger.info(create_bar(f"START ROMDownloader")) - start_files = get_tidy_files(os.path.join(str(self.out_dir), "*")) self.rclone_sync(ftp_dir=self.ftp_dir, @@ -149,7 +151,6 @@ def run(self, end_files = get_tidy_files(os.path.join(str(self.out_dir), "*")) if self.discord_url is not None: - name = f"ROMDownloader: {self.platform}" self.post_to_discord(start_files, end_files, @@ -179,8 +180,6 @@ def run(self, name=name ) - self.logger.info(create_bar(f"FINISH ROMDownloader")) - def rclone_sync(self, ftp_dir, out_dir=None, diff --git a/romsearch/modules/rommover.py b/romsearch/modules/rommover.py index 8630d6c..4c82f24 100644 --- a/romsearch/modules/rommover.py +++ b/romsearch/modules/rommover.py @@ -3,7 +3,12 @@ import shutil import romsearch -from ..util import load_yml, setup_logger, create_bar, unzip_file, load_json, save_json +from ..util import (load_yml, + setup_logger, + unzip_file, + load_json, + save_json + ) class ROMMover: @@ -14,6 +19,7 @@ def __init__(self, config_file=None, config=None, platform_config=None, + logger=None, ): """ROM Moving and cache updating tool @@ -25,14 +31,16 @@ def __init__(self, config_file (str, optional): path to config file. Defaults to None. config (dict, optional): configuration dictionary. Defaults to None. platform_config (dict, optional): platform configuration dictionary. Defaults to None. + logger (logging.Logger, optional): logger. Defaults to None. """ - logger_add_dir = str(os.path.join(platform, game)) - - self.logger = setup_logger(log_level="info", - script_name=f"ROMMover", - additional_dir=logger_add_dir, - ) + if logger is None: + logger_add_dir = str(os.path.join(platform, game)) + logger = setup_logger(log_level="info", + script_name=f"ROMMover", + additional_dir=logger_add_dir, + ) + self.logger = logger if config_file is None and config is None: raise ValueError("config_file or config must be specified") @@ -77,13 +85,9 @@ def run(self, rom_dict, ): - self.logger.info(create_bar(f"START ROMMover")) - roms_moved = self.move_roms(rom_dict) self.save_cache() - self.logger.info(create_bar(f"FINISH ROMMover")) - return roms_moved def move_roms(self, rom_dict): diff --git a/romsearch/modules/romparser.py b/romsearch/modules/romparser.py index 74bb8bd..4e6a8e9 100644 --- a/romsearch/modules/romparser.py +++ b/romsearch/modules/romparser.py @@ -6,7 +6,7 @@ import romsearch from ..util import (setup_logger, - create_bar, + load_yml, load_json, get_game_name, @@ -95,6 +95,7 @@ def __init__(self, platform_config=None, default_config=None, regex_config=None, + logger=None, ): """ROM parser tool @@ -108,6 +109,7 @@ def __init__(self, platform_config (dict, optional): platform configuration dictionary. Defaults to None. default_config (dict, optional): default configuration dictionary. Defaults to None. regex_config (dict, optional): regex configuration dictionary. Defaults to None. + logger (logging.Logger, optional): logger instance. Defaults to None. TODO: - Default implied languages from regions @@ -117,12 +119,13 @@ def __init__(self, raise ValueError("platform must be specified") self.platform = platform - logger_add_dir = str(os.path.join(platform, game)) - - self.logger = setup_logger(log_level="info", - script_name=f"ROMParser", - additional_dir=logger_add_dir, - ) + if logger is None: + logger_add_dir = str(os.path.join(platform, game)) + logger = setup_logger(log_level="info", + script_name=f"ROMParser", + additional_dir=logger_add_dir, + ) + self.logger = logger if config_file is None and config is None: raise ValueError("config_file or config must be specified") @@ -182,8 +185,6 @@ def run(self, ): """Run the ROM parser""" - self.logger.info(create_bar(f"START ROMParser")) - game_dict = {} for f in files: @@ -192,8 +193,6 @@ def run(self, # Include the priority game_dict[f]["priority"] = files[f]["priority"] - self.logger.info(create_bar(f"FINISH ROMParser")) - return game_dict def parse_file(self, @@ -220,7 +219,7 @@ def parse_file(self, ) file_dict["file_mod_time"] = file_time - self.logger.info(f"{f}: {file_dict}") + self.logger.debug(f"{f}: {file_dict}") return file_dict diff --git a/romsearch/modules/romsearch.py b/romsearch/modules/romsearch.py index b2a1f6d..16cc6b6 100644 --- a/romsearch/modules/romsearch.py +++ b/romsearch/modules/romsearch.py @@ -11,7 +11,6 @@ from .romparser import ROMParser from ..util import (load_yml, setup_logger, - create_bar, discord_push, split, get_short_name, @@ -25,6 +24,7 @@ def __init__(self, config=None, default_config=None, regex_config=None, + logger=None, ): """General search tool to get ROMs downloaded and organized into files @@ -42,7 +42,9 @@ def __init__(self, config = load_yml(config_file) self.config = config - self.logger = setup_logger("info", "ROMSearch") + if logger is None: + logger = setup_logger("info", "ROMSearch") + self.logger = logger # Read in the various pre-set configs we've got self.mod_dir = os.path.dirname(romsearch.__file__) @@ -92,9 +94,7 @@ def __init__(self, def run(self): """Run ROMSearch""" - self.logger.info(create_bar(f"START ROMSearch")) - - self.logger.info(f"Looping over platforms: {self.platforms}") + self.logger.info(f"Looping over platforms: {', '.join(self.platforms)}") all_roms_per_platform = {} @@ -113,6 +113,7 @@ def run(self): downloader = ROMDownloader(platform=platform, config=self.config, platform_config=platform_config, + logger=self.logger, ) downloader.run() @@ -143,6 +144,7 @@ def run(self): dat_parser = DATParser(platform=platform, config=self.config, platform_config=platform_config, + logger=self.logger, ) dat_parser.run() @@ -152,6 +154,7 @@ def run(self): config=self.config, default_config=self.default_config, regex_config=self.regex_config, + logger=self.logger, ) dupe_parser.run() @@ -160,16 +163,17 @@ def run(self): config=self.config, default_config=self.default_config, regex_config=self.regex_config, + logger=self.logger, ) all_games = finder.run(files=all_file_dict) - self.logger.info(f"Searching through {len(all_games)} games") + self.logger.info(f"Searching through {len(all_games)} game(s)") all_roms_moved = [] for i, game in enumerate(all_games): - self.logger.info(f"{i + 1}/{len(all_games)}: {game} (aliases {', '.join(all_games[game])}):") + self.logger.info(f"{i + 1}/{len(all_games)}: {game} (aliases {', '.join(all_games[game])})") # Parse by the short name, include the priority in there as well rom_files = {} @@ -195,6 +199,7 @@ def run(self): platform_config=platform_config, regex_config=self.regex_config, default_config=self.default_config, + logger=self.logger, ) rom_dict = parse.run(rom_files) @@ -205,6 +210,7 @@ def run(self): config=self.config, regex_config=self.regex_config, default_config=self.default_config, + logger=self.logger, ) rom_dict = chooser.run(rom_dict) @@ -214,7 +220,7 @@ def run(self): # Print out all the ROMs we've now matched rom_files = [f for f in rom_dict] - self.logger.info(f"Found ROM file(s): {rom_files}") + self.logger.info(f"Found ROM file(s): {', '.join(rom_files)}") if self.dry_run: self.logger.info("Dry run, will not move any files") @@ -227,7 +233,8 @@ def run(self): mover = ROMMover(platform=platform, game=game, config=self.config, - platform_config=platform_config + platform_config=platform_config, + logger=self.logger, ) roms_moved = mover.run(rom_dict) all_roms_moved.extend(roms_moved) @@ -257,6 +264,4 @@ def run(self): if not all_file_dict[f]["matched"]: self.logger.warning(f"{f} not matched to anything") - self.logger.info(create_bar(f"FINISH ROMSearch")) - return True diff --git a/romsearch/util/__init__.py b/romsearch/util/__init__.py index 2710470..e84a27e 100644 --- a/romsearch/util/__init__.py +++ b/romsearch/util/__init__.py @@ -1,11 +1,10 @@ from .discord import discord_push from .general import split, get_parent_name from .io import load_yml, unzip_file, load_json, save_json -from .logger import setup_logger, create_bar +from .logger import setup_logger from .regex_matching import get_file_pattern, get_bracketed_file_pattern, get_game_name, get_short_name __all__ = [ - "create_bar", "setup_logger", "load_yml", "get_bracketed_file_pattern", diff --git a/romsearch/util/logger.py b/romsearch/util/logger.py index 210bdf9..725dbdd 100644 --- a/romsearch/util/logger.py +++ b/romsearch/util/logger.py @@ -1,10 +1,10 @@ import logging -import math import os +import sys from logging.handlers import RotatingFileHandler -from pathvalidate import sanitize_filename -from .. import __version__ +import colorlog +from pathvalidate import sanitize_filename def setup_logger(log_level, @@ -72,18 +72,18 @@ def setup_logger(log_level, logger.critical(f"Invalid log level '{log_level}', defaulting to 'INFO'") logger.setLevel(logging.INFO) - # Define the log message format - formatter = logging.Formatter(fmt='%(asctime)s %(levelname)s: %(message)s', datefmt='%m/%d/%y %I:%M %p') + # Define the log message format for the log files + logfile_formatter = logging.Formatter(fmt='%(asctime)s %(levelname)s: %(message)s', datefmt='%m/%d/%y %I:%M %p') # Create a RotatingFileHandler for log files handler = RotatingFileHandler(log_file, delay=True, mode="w", backupCount=max_logs) - handler.setFormatter(formatter) + handler.setFormatter(logfile_formatter) # Add the file handler to the logger logger.addHandler(handler) # Configure console logging with the specified log level - console_handler = logging.StreamHandler() + console_handler = colorlog.StreamHandler(sys.stdout) if log_level == 'DEBUG': console_handler.setLevel(logging.DEBUG) elif log_level == 'INFO': @@ -92,6 +92,7 @@ def setup_logger(log_level, console_handler.setLevel(logging.CRITICAL) # Add the console handler to the logger + console_handler.setFormatter(colorlog.ColoredFormatter("%(log_color)s%(levelname)s: %(message)s")) logger.addHandler(console_handler) # Overwrite previous logger if exists @@ -99,31 +100,4 @@ def setup_logger(log_level, logging.getLogger(script_name).addHandler(handler) logging.getLogger(script_name).addHandler(console_handler) - # Insert version number at the head of every log file - name = script_name.replace("_", " ").upper() - logger.info(create_bar(f"{name} Version: {__version__}")) - return logger - - -def create_bar(middle_text): - """ - Creates a separation bar with provided text in the center - - Args: - middle_text (str): The text to place in the center of the separation bar - - Returns: - str: The formatted separation bar - """ - total_length = 80 - if len(middle_text) == 1: - remaining_length = total_length - len(middle_text) - 2 - left_side_length = 0 - right_side_length = remaining_length - return f"\n{middle_text * left_side_length}{middle_text}{middle_text * right_side_length}\n" - else: - remaining_length = total_length - len(middle_text) - 4 - left_side_length = math.floor(remaining_length / 2) - right_side_length = remaining_length - left_side_length - return f"\n{'*' * left_side_length} {middle_text} {'*' * right_side_length}\n"