From 43fbc312cfe9f1f8d8222f3e80a39ea5394038ea Mon Sep 17 00:00:00 2001 From: Jerrie <70805800+Jerrie-Aries@users.noreply.github.com> Date: Sat, 15 Jul 2023 19:45:36 +0800 Subject: [PATCH] Enable discord.py logger by default. (#3216) * Enable `discord.py` logger by default. * Revert: - Restore import orders - Logging stuff is now completely handled in `core.models.configure_logging` * Update logging configurations * Updated changelog * Fix overflow characters in logs when using `?debug` command. * Update changelog --------- Co-authored-by: Taku <45324516+Taaku18@users.noreply.github.com> --- CHANGELOG.md | 9 +- bot.py | 41 +------- cogs/utility.py | 23 +---- core/config.py | 1 + core/config_help.json | 9 ++ core/models.py | 214 +++++++++++++++++++++++++++++++----------- 6 files changed, 185 insertions(+), 112 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index fad0639ae3..d90473d40d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,12 +14,17 @@ however, insignificant breaking changes do not guarantee a major version bump, s - Reply not being forwarded from DM. (PR [#3239](https://github.com/modmail-dev/modmail/pull/3239)) ### Added -- New .env config option: `REGISTRY_PLUGINS_ONLY`, restricts to only allow adding registry plugins. ([PR #3247](https://github.com/modmail-dev/modmail/pull/3247)) - `?log key ` to retrieve the log link and view a preview using a log key. ([PR #3196](https://github.com/modmail-dev/Modmail/pull/3196)) +- `REGISTRY_PLUGINS_ONLY`, environment variable, when set, restricts to only allow adding registry plugins. ([PR #3247](https://github.com/modmail-dev/modmail/pull/3247)) +- `DISCORD_LOG_LEVEL` environment variable to set the log level of discord.py. ([PR #3216](https://github.com/modmail-dev/Modmail/pull/3216)) ### Changed -- Guild icons in embed footers and author urls now have a fixed size of 128. ([PR #3261](https://github.com/modmail-dev/modmail/pull/3261)) - Repo moved to https://github.com/modmail-dev/modmail. +- Guild icons in embed footers and author urls now have a fixed size of 128. ([PR #3261](https://github.com/modmail-dev/modmail/pull/3261)) +- Discord.py internal logging is now enabled by default. ([PR #3216](https://github.com/modmail-dev/Modmail/pull/3216)) + +### Internal +- Renamed `Bot.log_file_name` to `Bot.log_file_path`. Log files are now created at `temp/logs/modmail.log`. ([PR #3216](https://github.com/modmail-dev/Modmail/pull/3216)) # v4.0.2 diff --git a/bot.py b/bot.py index 8f2f74e00c..45530a908f 100644 --- a/bot.py +++ b/bot.py @@ -52,7 +52,6 @@ logger = getLogger(__name__) - temp_dir = os.path.join(os.path.dirname(os.path.abspath(__file__)), "temp") if not os.path.exists(temp_dir): os.mkdir(temp_dir) @@ -84,8 +83,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 self.startup() @@ -182,29 +184,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 parse_version(__version__) @@ -1801,16 +1780,6 @@ def main(): ) sys.exit(0) - # 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 b3a6d49aeb..47889c2c93 100644 --- a/cogs/utility.py +++ b/cogs/utility.py @@ -401,13 +401,7 @@ async def sponsors(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: @@ -433,7 +427,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" @@ -455,12 +449,8 @@ 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: @@ -491,12 +481,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 9a033167b7..fa48864aed 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 e7ebb9590d..f5b08d64ad 100644 --- a/core/config_help.json +++ b/core/config_help.json @@ -1129,6 +1129,15 @@ "This configuration can only to be set through `.env` file or environment (config) variables." ] }, + "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." + ] + }, "enable_plugins": { "default": "Yes", "description": "Whether plugins should be enabled and loaded into Modmail.", diff --git a/core/models.py b/core/models.py index 2eab1ceebb..29f6af71bb 100644 --- a/core/models.py +++ b/core/models.py @@ -1,16 +1,19 @@ import logging +import os import re import sys -import os +import _string + from difflib import get_close_matches from enum import IntEnum +from logging import FileHandler, StreamHandler, Handler from logging.handlers import RotatingFileHandler from string import Formatter +from typing import Optional import discord from discord.ext import commands -import _string try: from colorama import Fore, Style @@ -23,29 +26,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): @@ -94,18 +74,92 @@ 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", +) -ch_debug = None + +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`.") + + 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: @@ -118,33 +172,71 @@ def getLogger(name=None) -> ModmailLogger: return logger -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) - - -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") - 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) + 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) - if level is not None: - log_level = level + 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.") - ch.setLevel(log_level) - for logger in loggers: - logger.setLevel(log_level) - logger.addHandler(ch_debug) +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 _Default: @@ -271,6 +363,18 @@ async def ack(self): return +class PermissionLevel(IntEnum): + OWNER = 5 + ADMINISTRATOR = 4 + ADMIN = 4 + MODERATOR = 3 + MOD = 3 + SUPPORTER = 2 + RESPONDER = 2 + REGULAR = 1 + INVALID = -1 + + class DMDisabled(IntEnum): NONE = 0 NEW_THREADS = 1