diff --git a/bot.py b/bot.py index b3d1a34fa5..5c53e7ce39 100644 --- a/bot.py +++ b/bot.py @@ -4,7 +4,6 @@ import asyncio import copy import hashlib -import logging import os import re import string @@ -87,8 +86,11 @@ def __init__(self): self.threads = ThreadManager(self) - self.log_file_name = os.path.join(temp_dir, f"{self.token.split('.')[0]}.log") - self._configure_logging() + log_dir = os.path.join(temp_dir, "logs") + if not os.path.exists(log_dir): + os.mkdir(log_dir) + self.log_file_path = os.path.join(log_dir, "modmail.log") + configure_logging(self) self.plugin_db = PluginDatabaseClient(self) # Deprecated @@ -188,29 +190,6 @@ async def load_extensions(self): logger.exception("Failed to load %s.", cog) logger.line("debug") - def _configure_logging(self): - level_text = self.config["log_level"].upper() - logging_levels = { - "CRITICAL": logging.CRITICAL, - "ERROR": logging.ERROR, - "WARNING": logging.WARNING, - "INFO": logging.INFO, - "DEBUG": logging.DEBUG, - } - logger.line() - - log_level = logging_levels.get(level_text) - if log_level is None: - log_level = self.config.remove("log_level") - logger.warning("Invalid logging level set: %s.", level_text) - logger.warning("Using default logging level: INFO.") - else: - logger.info("Logging level: %s", level_text) - - logger.info("Log file: %s", self.log_file_name) - configure_logging(self.log_file_name, log_level) - logger.debug("Successfully configured logging.") - @property def version(self): return version.parse(__version__) @@ -1850,16 +1829,6 @@ def main(): discord.__version__, ) - # Set up discord.py internal logging - if os.environ.get("LOG_DISCORD"): - logger.debug(f"Discord logging enabled: {os.environ['LOG_DISCORD'].upper()}") - d_logger = logging.getLogger("discord") - - d_logger.setLevel(os.environ["LOG_DISCORD"].upper()) - handler = logging.FileHandler(filename="discord.log", encoding="utf-8", mode="w") - handler.setFormatter(logging.Formatter("%(asctime)s:%(levelname)s:%(name)s: %(message)s")) - d_logger.addHandler(handler) - bot = ModmailBot() bot.run() diff --git a/cogs/utility.py b/cogs/utility.py index 3eff051f40..3c807abacc 100644 --- a/cogs/utility.py +++ b/cogs/utility.py @@ -384,13 +384,7 @@ async def about(self, ctx): async def debug(self, ctx): """Shows the recent application logs of the bot.""" - log_file_name = self.bot.token.split(".")[0] - - with open( - os.path.join(os.path.dirname(os.path.abspath(__file__)), f"../temp/{log_file_name}.log"), - "r+", - encoding="utf-8", - ) as f: + with open(self.bot.log_file_path, "r+", encoding="utf-8") as f: logs = f.read().strip() if not logs: @@ -416,7 +410,7 @@ async def debug(self, ctx): msg = "```Haskell\n" msg += line if len(msg) + 3 > 2000: - msg = msg[:1993] + "[...]```" + msg = msg[:1992] + "[...]```" messages.append(msg) msg = "```Haskell\n" @@ -438,12 +432,7 @@ async def debug_hastebin(self, ctx): """Posts application-logs to Hastebin.""" haste_url = os.environ.get("HASTE_URL", "https://hastebin.cc") - log_file_name = self.bot.token.split(".")[0] - - with open( - os.path.join(os.path.dirname(os.path.abspath(__file__)), f"../temp/{log_file_name}.log"), - "rb+", - ) as f: + with open(self.bot.log_file_path, "rb+") as f: logs = BytesIO(f.read().strip()) try: @@ -474,12 +463,7 @@ async def debug_hastebin(self, ctx): async def debug_clear(self, ctx): """Clears the locally cached logs.""" - log_file_name = self.bot.token.split(".")[0] - - with open( - os.path.join(os.path.dirname(os.path.abspath(__file__)), f"../temp/{log_file_name}.log"), - "w", - ): + with open(self.bot.log_file_path, "w"): pass await ctx.send( embed=discord.Embed(color=self.bot.main_color, description="Cached logs are now cleared.") diff --git a/core/config.py b/core/config.py index b483fddafa..e70210cddf 100644 --- a/core/config.py +++ b/core/config.py @@ -178,6 +178,7 @@ class ConfigManager: "disable_updates": False, # Logging "log_level": "INFO", + "discord_log_level": "INFO", # data collection "data_collection": True, } diff --git a/core/config_help.json b/core/config_help.json index 53f34dd4d3..9e6adab51e 100644 --- a/core/config_help.json +++ b/core/config_help.json @@ -373,17 +373,17 @@ "To disable thread cooldown, do `{prefix}config del thread_cooldown`." ] }, - "log_expiration": { - "default": "Never", - "description": "The duration closed threads will be stored within the database before deletion. Logs that have been closed for longer than this duration will be deleted automatically.", - "examples": [ - "`{prefix}config set log_expiration P12DT3H` (stands for 12 days and 3 hours in [ISO-8601 Duration Format](https://en.wikipedia.org/wiki/ISO_8601#Durations))", - "`{prefix}config set log_expiration 3 days and 5 hours` (accepted readable time)" - ], - "notes": [ - "To disable log expiration, do `{prefix}config del log_expiration`." - ] - }, + "log_expiration": { + "default": "Never", + "description": "The duration closed threads will be stored within the database before deletion. Logs that have been closed for longer than this duration will be deleted automatically.", + "examples": [ + "`{prefix}config set log_expiration P12DT3H` (stands for 12 days and 3 hours in [ISO-8601 Duration Format](https://en.wikipedia.org/wiki/ISO_8601#Durations))", + "`{prefix}config set log_expiration 3 days and 5 hours` (accepted readable time)" + ], + "notes": [ + "To disable log expiration, do `{prefix}config del log_expiration`." + ] + }, "thread_cancelled": { "default": "\"Cancelled\"", "description": "This is the message to display when a thread times out and creation is cancelled.", @@ -1182,12 +1182,20 @@ "If you would like to display the top role of a user regardless of if it's hoisted or not, disable `use_hoisted_top_role`." ] }, - "registry_plugins_only": { - "default": "True", - "description": "Controls if the bot is only allowed to install plugins specified in the registry.", - "examples": [ - "`{prefix}config set registry_plugins_only False`" - ], - "notes": [] - } + "registry_plugins_only": { + "default": "True", + "description": "Controls if the bot is only allowed to install plugins specified in the registry.", + "examples": [ + "`{prefix}config set registry_plugins_only False`" + ], + "notes": [] + }, + "discord_log_level": { + "default": "INFO", + "description": "The `discord.py` library logging level for logging to stdout.", + "examples": [], + "notes": [ + "This configuration can only to be set through `.env` file or environment (config) variables." + ] + } } \ No newline at end of file diff --git a/core/models.py b/core/models.py index c5eefbd05e..976abbbf81 100644 --- a/core/models.py +++ b/core/models.py @@ -4,8 +4,10 @@ import sys from difflib import get_close_matches from enum import IntEnum +from logging import FileHandler, Handler, StreamHandler from logging.handlers import RotatingFileHandler from string import Formatter +from typing import Optional import _string import discord @@ -22,29 +24,6 @@ Fore = Style = type("Dummy", (object,), {"__getattr__": lambda self, item: ""})() -class PermissionLevel(IntEnum): - OWNER = 5 - ADMINISTRATOR = 4 - ADMIN = 4 - MODERATOR = 3 - MOD = 3 - SUPPORTER = 2 - RESPONDER = 2 - REGULAR = 1 - INVALID = -1 - - -class InvalidConfigError(commands.BadArgument): - def __init__(self, msg, *args): - super().__init__(msg, *args) - self.msg = msg - - @property - def embed(self): - # Single reference of Color.red() - return discord.Embed(title="Error", description=self.msg, color=discord.Color.red()) - - class ModmailLogger(logging.Logger): @staticmethod def _debug_(*msgs): @@ -93,18 +72,89 @@ def line(self, level="info"): ) -logging.setLoggerClass(ModmailLogger) -log_level = logging.INFO -loggers = set() +class FileFormatter(logging.Formatter): + ansi_escape = re.compile(r"\x1B\[[0-?]*[ -/]*[@-~]") + + def format(self, record): + record.msg = self.ansi_escape.sub("", record.msg) + return super().format(record) -ch = logging.StreamHandler(stream=sys.stdout) -ch.setLevel(log_level) -formatter = logging.Formatter( + +log_stream_formatter = logging.Formatter( "%(asctime)s %(name)s[%(lineno)d] - %(levelname)s: %(message)s", datefmt="%m/%d/%y %H:%M:%S" ) -ch.setFormatter(formatter) +log_file_formatter = FileFormatter( + "%(asctime)s %(name)s[%(lineno)d] - %(levelname)s: %(message)s", + datefmt="%Y-%m-%d %H:%M:%S", +) + + +def create_log_handler( + filename: Optional[str] = None, + *, + rotating: bool = False, + level: int = logging.DEBUG, + mode: str = "a+", + encoding: str = "utf-8", + maxBytes: int = 28000000, + backupCount: int = 1, + **kwargs, +) -> Handler: + """ + Creates a pre-configured log handler. This function is made for consistency's sake with + pre-defined default values for parameters and formatters to pass to handler class. + Additional keyword arguments also can be specified, just in case. + Plugin developers should not use this and use `models.getLogger` instead. + Parameters + ---------- + filename : Optional[Path] + Specifies that a `FileHandler` or `RotatingFileHandler` be created, using the specified filename, + rather than a `StreamHandler`. Defaults to `None`. + rotating : bool + Whether the file handler should be the `RotatingFileHandler`. Defaults to `False`. Note, this + argument only compatible if the `filename` is specified, otherwise `ValueError` will be raised. + level : int + The root logger level for the handler. Defaults to `logging.DEBUG`. + mode : str + If filename is specified, open the file in this mode. Defaults to 'a+'. + encoding : str + If this keyword argument is specified along with filename, its value is used when the `FileHandler` is created, + and thus used when opening the output file. Defaults to 'utf-8'. + maxBytes : int + The max file size before the rollover occurs. Defaults to 28000000 (28MB). Rollover occurs whenever the current + log file is nearly `maxBytes` in length; but if either of `maxBytes` or `backupCount` is zero, + rollover never occurs, so you generally want to set `backupCount` to at least 1. + backupCount : int + Max number of backup files. Defaults to 1. If this is set to zero, rollover will never occur. + Returns + ------- + `StreamHandler` when `filename` is `None`, otherwise `FileHandler` or `RotatingFileHandler` + depending on the `rotating` value. + """ + if filename is None and rotating: + raise ValueError("`filename` must be set to instantiate a `RotatingFileHandler`.") -ch_debug = None + if filename is None: + handler = StreamHandler(stream=sys.stdout, **kwargs) + handler.setFormatter(log_stream_formatter) + elif not rotating: + handler = FileHandler(filename, mode=mode, encoding=encoding, **kwargs) + handler.setFormatter(log_file_formatter) + else: + handler = RotatingFileHandler( + filename, mode=mode, encoding=encoding, maxBytes=maxBytes, backupCount=backupCount, **kwargs + ) + handler.setFormatter(log_file_formatter) + + handler.setLevel(level) + return handler + + +logging.setLoggerClass(ModmailLogger) +log_level = logging.INFO +loggers = set() +ch = create_log_handler(level=log_level) +ch_debug: Optional[RotatingFileHandler] = None def getLogger(name=None) -> ModmailLogger: @@ -117,39 +167,88 @@ def getLogger(name=None) -> ModmailLogger: return logger -class FileFormatter(logging.Formatter): - ansi_escape = re.compile(r"\x1B\[[:;<=>?@]*[ -/]*[@-~]") - - def format(self, record): - record.msg = self.ansi_escape.sub("", record.msg) - return super().format(record) - - -def configure_logging(name, level=None): +def configure_logging(bot) -> None: global ch_debug, log_level - ch_debug = RotatingFileHandler(name, mode="a+", maxBytes=48000, backupCount=1, encoding="utf-8") + logger = getLogger(__name__) + level_text = bot.config["log_level"].upper() + logging_levels = { + "CRITICAL": logging.CRITICAL, + "ERROR": logging.ERROR, + "WARNING": logging.WARNING, + "INFO": logging.INFO, + "DEBUG": logging.DEBUG, + } + logger.line() + + level = logging_levels.get(level_text) + if level is None: + level = bot.config.remove("log_level") + logger.warning("Invalid logging level set: %s.", level_text) + logger.warning("Using default logging level: %s.", level) + level = logging_levels[level] + else: + logger.info("Logging level: %s", level_text) + log_level = level + + logger.info("Log file: %s", bot.log_file_path) + ch_debug = create_log_handler(bot.log_file_path, rotating=True) + ch.setLevel(log_level) - formatter_debug = FileFormatter( - "%(asctime)s %(name)s[%(lineno)d] - %(levelname)s: %(message)s", - datefmt="%Y-%m-%d %H:%M:%S", - ) - ch_debug.setFormatter(formatter_debug) - ch_debug.setLevel(logging.DEBUG) + for log in loggers: + log.setLevel(log_level) + log.addHandler(ch_debug) + + # Set up discord.py logging + d_level_text = bot.config["discord_log_level"].upper() + d_level = logging_levels.get(d_level_text) + if d_level is None: + d_level = bot.config.remove("discord_log_level") + logger.warning("Invalid discord logging level set: %s.", d_level_text) + logger.warning("Using default discord logging level: %s.", d_level) + d_level = logging_levels[d_level] + d_logger = logging.getLogger("discord") + d_logger.setLevel(d_level) + + non_verbose_log_level = max(d_level, logging.INFO) + stream_handler = create_log_handler(level=non_verbose_log_level) + if non_verbose_log_level != d_level: + logger.info("Discord logging level (stdout): %s.", logging.getLevelName(non_verbose_log_level)) + logger.info("Discord logging level (logfile): %s.", logging.getLevelName(d_level)) + else: + logger.info("Discord logging level: %s.", logging.getLevelName(d_level)) + d_logger.addHandler(stream_handler) + d_logger.addHandler(ch_debug) + + logger.debug("Successfully configured logging.") - if level is not None: - log_level = level - ch.setLevel(log_level) +class InvalidConfigError(commands.BadArgument): + def __init__(self, msg, *args): + super().__init__(msg, *args) + self.msg = msg - for logger in loggers: - logger.setLevel(log_level) - logger.addHandler(ch_debug) + @property + def embed(self): + # Single reference of Color.red() + return discord.Embed(title="Error", description=self.msg, color=discord.Color.red()) class _Default: pass +class PermissionLevel(IntEnum): + OWNER = 5 + ADMINISTRATOR = 4 + ADMIN = 4 + MODERATOR = 3 + MOD = 3 + SUPPORTER = 2 + RESPONDER = 2 + REGULAR = 1 + INVALID = -1 + + Default = _Default()