From b77c70e49742c73b75a3fd68a963bf55dd982f97 Mon Sep 17 00:00:00 2001 From: ZRunner Date: Tue, 3 Oct 2023 17:27:07 -0400 Subject: [PATCH] feat(log): rewrite logging handlers --- src/boot_utils.py | 28 +++++++++++++++------------- src/cobot.py | 5 +++-- src/firebase/client.py | 20 ++++++++++---------- src/modules/admin/main.py | 14 ++++++++------ src/modules/errors/main.py | 17 ++++++++++------- src/modules/giveaways/main.py | 6 ++++-- start.py | 4 +++- 7 files changed, 53 insertions(+), 41 deletions(-) diff --git a/src/boot_utils.py b/src/boot_utils.py index caeee69..2e89d66 100644 --- a/src/boot_utils.py +++ b/src/boot_utils.py @@ -15,30 +15,32 @@ def setup_start_parser(): "Create a parser for the command-line interface" parser = argparse.ArgumentParser() parser.add_argument('--beta', '-b', help="Use the beta bot instead of the release", action="store_true") - return parser def setup_logger(): """Setup the logger used by the bot It should use both console and a debug file""" - log = logging.getLogger("cobot") - log_format = logging.Formatter("%(asctime)s %(levelname)s: %(message)s", datefmt="[%d/%m/%Y %H:%M:%S]") - + # console logging + stream_handler = logging.StreamHandler(sys.stdout) # file logging file_handler = RotatingFileHandler("logs/debug.log", maxBytes=int(1e6), backupCount=2, delay=True) - file_handler.setLevel(logging.DEBUG) - file_handler.setFormatter(log_format) - # console logging - stream_handler = logging.StreamHandler(sys.stdout) - stream_handler.setLevel(logging.DEBUG) + log_format = logging.Formatter( + "[{asctime}] {levelname:<7}: [{name}] {message}", + datefmt="%Y-%m-%d %H:%M:%S", style='{' + ) + + file_handler.setFormatter(log_format) stream_handler.setFormatter(log_format) - log.addHandler(file_handler) - log.addHandler(stream_handler) + # add handlers to root logger + root_logger = logging.getLogger() + root_logger.addHandler(file_handler) + root_logger.addHandler(stream_handler) + root_logger.setLevel(logging.INFO) - log.setLevel(logging.DEBUG) - return log + # set cobot logger to debug + logging.getLogger("cobot").setLevel(logging.DEBUG) async def load_cogs(bot: "CObot"): "Load the bot modules" diff --git a/src/cobot.py b/src/cobot.py index 4b73bad..aef0c14 100644 --- a/src/cobot.py +++ b/src/cobot.py @@ -1,3 +1,4 @@ +import logging import sys from typing import Optional, Union @@ -6,7 +7,6 @@ from src.firebase.client import FirebaseDB -from .boot_utils import setup_logger from .config import Config @@ -28,7 +28,7 @@ def __init__(self, status: discord.Status, beta: bool): super().__init__(command_prefix=commands.when_mentioned, owner_ids=owner_ids, status=status, allowed_mentions=allowed_mentions, intents=intents, enable_debug_events=True) self.beta = beta # if the bot is in beta mode - self.log = setup_logger() # logs module + self.log = logging.getLogger("cobot") self.zws = "\u200B" # here's a zero width space self.fb = FirebaseDB( # firebase client "firebaseServiceAccount.json", @@ -47,6 +47,7 @@ async def on_error(self, event_method: Union[Exception, str], *_args, **_kwargs) self.dispatch("error", error, f"While handling event `{event_method}`") async def on_app_cmd_error(self, interaction: discord.Interaction, error: discord.app_commands.AppCommandError): + "Dispatch a custom 'interaction_error' when an app command raises an error" self.dispatch("interaction_error", interaction, error) async def fetch_app_commands(self): diff --git a/src/firebase/client.py b/src/firebase/client.py index 4244d39..9f6b127 100644 --- a/src/firebase/client.py +++ b/src/firebase/client.py @@ -18,7 +18,7 @@ def __init__(self, filename: str, realtime_url: str): 'databaseURL': realtime_url, }) self.cache = FirebaseCacheControler() - self.log = logging.getLogger("cobot") + self.log = logging.getLogger("cobot.firebase") async def get_giveaways(self) -> AsyncGenerator[GiveawayData, None]: "Get a generator of giveaway documents" @@ -26,7 +26,7 @@ async def get_giveaways(self) -> AsyncGenerator[GiveawayData, None]: for gaw in self.cache.get_giveaways(): yield gaw return - self.log.debug("[firebase] Fetching giveaways") + self.log.debug("Fetching giveaways") ref = db.reference("giveaways") snapshot: dict[str, RawGiveawayData] = ref.get() # type: ignore parsed_giveaways: list[GiveawayData] = [ @@ -49,7 +49,7 @@ async def get_active_giveaways(self) -> AsyncGenerator[GiveawayData, None]: for gaw in self.cache.get_active_giveaways(): yield gaw return - self.log.debug("[firebase] Fetching active giveaways") + self.log.debug("Fetching active giveaways") ref = db.reference("giveaways") snapshot: dict[str, RawGiveawayData] = ref.order_by_child("ended").equal_to(False).get() # type: ignore parsed_giveaways: list[GiveawayData] = [ @@ -69,7 +69,7 @@ async def get_giveaway(self, giveaway_id: str) -> Optional[GiveawayData]: "Get a giveaway document" if gaw := self.cache.get_giveaway(giveaway_id): return gaw - self.log.debug("[firebase] Fetching giveaway %s", giveaway_id) + self.log.debug("Fetching giveaway %s", giveaway_id) ref = db.reference(f"giveaways/{giveaway_id}") snapshot: Optional[RawGiveawayData] = ref.get() # type: ignore if snapshot is None: @@ -85,7 +85,7 @@ async def get_giveaway(self, giveaway_id: str) -> Optional[GiveawayData]: async def create_giveaway(self, data: GiveawayData): "Create a giveaway document" - self.log.info("[firebase] Creating new giveaway %s", data["id"]) + self.log.info("Creating new giveaway %s", data["id"]) ref = db.reference("giveaways") ref.child(data["id"]).set({ **data, @@ -95,7 +95,7 @@ async def create_giveaway(self, data: GiveawayData): async def close_giveaway(self, giveaway_id: str, winners: list[int]): "Mark a giveaway as ended" - self.log.info("[firebase] Marking giveaway %s as ended", giveaway_id) + self.log.info("Marking giveaway %s as ended", giveaway_id) ref = db.reference(f"giveaways/{giveaway_id}") ref.update({ "ended": True, @@ -105,7 +105,7 @@ async def close_giveaway(self, giveaway_id: str, winners: list[int]): async def delete_giveaway(self, giveaway_id: str): "Delete a giveaway document and its participants" - self.log.info("[firebase] Deleting giveaway %s", giveaway_id) + self.log.info("Deleting giveaway %s", giveaway_id) # remove giveaway entry ref = db.reference(f"giveaways/{giveaway_id}") ref.delete() @@ -119,7 +119,7 @@ async def get_giveaways_participants(self, giveaway_id: str) -> Optional[list[in "Get a list of participants for a giveaway" if self.cache.are_participants_sync(giveaway_id): return self.cache.get_participants(giveaway_id) - self.log.debug("[firebase] Fetching participants for giveaway %s", giveaway_id) + self.log.debug("Fetching participants for giveaway %s", giveaway_id) ref = db.reference(f"giveaways_participants/{giveaway_id}") snapshot: Optional[dict[str, Literal[True]]] = ref.get() # type: ignore if snapshot is None: @@ -133,14 +133,14 @@ async def check_giveaway_participant(self, giveaway_id: str, user_id: int) -> bo if self.cache.are_participants_sync(giveaway_id): if participants := self.cache.get_participants(giveaway_id): return user_id in participants - self.log.debug("[firebase] Fetching participant %s for giveaway %s", user_id, giveaway_id) + self.log.debug("Fetching participant %s for giveaway %s", user_id, giveaway_id) ref = db.reference(f"giveaways_participants/{giveaway_id}/{user_id}") snapshot: Optional[Literal[True]] = ref.get() # type: ignore return snapshot is not None async def add_giveaway_participant(self, giveaway_id: str, user_id: int): "Add a participant to a giveaway" - self.log.debug("[firebase] Adding participant %s to giveaway %s", user_id, giveaway_id) + self.log.debug("Adding participant %s to giveaway %s", user_id, giveaway_id) ref = db.reference(f"giveaways_participants/{giveaway_id}/{user_id}") ref.set(True) self.cache.add_participant(giveaway_id, user_id) diff --git a/src/modules/admin/main.py b/src/modules/admin/main.py index cd191ec..19f7ea9 100644 --- a/src/modules/admin/main.py +++ b/src/modules/admin/main.py @@ -1,4 +1,5 @@ import io +import logging import os import sys import textwrap @@ -32,6 +33,7 @@ class AdminCog(commands.Cog): def __init__(self, bot: CObot): self.bot = bot self._last_result: Any = None + self.log = logging.getLogger("cobot.admin") group = discord.app_commands.Group( name="admin", @@ -81,7 +83,7 @@ async def reboot(self, interaction: COInteraction): "Restart the bot" await interaction.response.send_message(content="Reboot in progress...") await self.cleanup_workspace() - self.bot.log.info("Restarting the process") + self.log.info("Restarting the process") os.execl(sys.executable, sys.executable, *sys.argv) @group.command(name="shutdown") @@ -92,7 +94,7 @@ async def shutdown(self, interaction: COInteraction): await self.cleanup_workspace() await interaction.edit_original_response(content="Shutting down...") await self.bot.change_presence(status=discord.Status('offline')) - self.bot.log.info("Shutting down the process, requested by %s", interaction.user) + self.log.info("Shutting down the process, requested by %s", interaction.user) await self.bot.close() @group.command(name="sync-commands") @@ -102,7 +104,7 @@ async def sync_app_commands(self, interaction: COInteraction): await interaction.response.defer() cmds = await self.bot.tree.sync() txt = f"{len(cmds)} global commands synced" - self.bot.log.info(txt) + self.log.info(txt) await interaction.followup.send(txt + '!') @group.command(name="change-activity") @@ -140,19 +142,19 @@ async def _eval(self, ctx: commands.Context, *, body: str): stdout = io.StringIO() try: to_compile = f'async def func():\n{textwrap.indent(body, " ")}' - except Exception as err: + except Exception as err: # pylint: disable=broad-except self.bot.dispatch("error", err, ctx) return try: exec(to_compile, env) # pylint: disable=exec-used - except Exception as err: + except Exception as err: # pylint: disable=broad-except return await ctx.reply(f'```py\n{err.__class__.__name__}: {err}\n```') func = env['func'] try: with redirect_stdout(stdout): ret = await func() - except Exception as err: + except Exception as err: # pylint: disable=broad-except value = stdout.getvalue() await ctx.reply(f'```py\n{value}{traceback.format_exc()[:1990]}\n```') else: diff --git a/src/modules/errors/main.py b/src/modules/errors/main.py index a9ebac7..a8c8e1c 100644 --- a/src/modules/errors/main.py +++ b/src/modules/errors/main.py @@ -1,7 +1,9 @@ +import logging import os import sys import traceback from typing import Optional, Union + import discord from discord.ext import commands, tasks @@ -28,6 +30,7 @@ def __init__(self, bot: CObot): self.bot = bot # map of user ID and number of cooldown errors recently hit self.cooldown_pool: dict[int, int] = {} + self.log = logging.getLogger("cobot.errors") async def cog_load(self): # pylint: disable=no-member @@ -123,7 +126,7 @@ async def on_command_error(self, ctx: commands.Context, error: Exception): return # All other Errors not returned come here... And we can just print the default TraceBack. - self.bot.log.warning(f'Ignoring exception in command {ctx.message.content}:') + self.log.warning('Ignoring exception in command %s:', ctx.message.content) await self.on_error(error,ctx) @commands.Cog.listener() @@ -157,7 +160,7 @@ async def on_interaction_error(self, interaction: COInteraction, error: BaseExce elif interaction.type == discord.InteractionType.autocomplete: await self.on_error(error, f"Command autocompletion | {guild}") else: - self.bot.log.warn(f"Unhandled interaction error type: {interaction.type}") + self.log.warning("Unhandled interaction error type: %s", interaction.type) await self.on_error(error, None) await send("Oops, an error occured while executing this command :confused:", ephemeral=True) @@ -174,7 +177,7 @@ async def on_error(self, error: BaseException, ctx: Optional[AllowedCtx] = None) try: # if this is only an interaction too slow, don't report in bug channel if isinstance(error, discord.NotFound) and error.text == "Unknown interaction": - self.bot.log.warning(f"[on_error] {error}", exc_info=exc_info) + self.log.warning(error, exc_info=exc_info) return # get traceback info if isinstance(ctx, discord.Message): @@ -197,9 +200,9 @@ async def on_error(self, error: BaseException, ctx: Optional[AllowedCtx] = None) channel_name = get_channel_name(ctx) context = f"{ctx.guild.name} | {channel_name}" await self.send_error_msg_autoformat(context, trace) - self.bot.log.warning(f"[on_error] {error}", exc_info=exc_info) - except Exception as err: - self.bot.log.error(f"[on_error] {err}", exc_info=sys.exc_info()) + self.log.warning(error, exc_info=exc_info) + except Exception as err: # pylint: disable=broad-except + self.log.error(err, exc_info=sys.exc_info()) async def send_error_msg_autoformat(self, context: str, python_message: str): """Envoie un message dans le salon d'erreur""" @@ -216,7 +219,7 @@ async def senf_err_msg(self, msg: str): """Envoie un message dans le salon d'erreur""" errors_channel: discord.TextChannel = self.bot.get_channel(self.bot.config["ERRORS_CHANNEL_ID"]) # type: ignore if errors_channel is None: - self.bot.log.critical("[on_error] Cannot find errors channel") + self.log.critical("Cannot find errors channel") return False if len(msg) > 2000: if msg.endswith("```"): diff --git a/src/modules/giveaways/main.py b/src/modules/giveaways/main.py index 9efa653..0fe3132 100644 --- a/src/modules/giveaways/main.py +++ b/src/modules/giveaways/main.py @@ -1,3 +1,4 @@ +import logging import random from datetime import timedelta from typing import Optional @@ -22,6 +23,7 @@ def __init__(self, bot: CObot): self.bot = bot self.embed_color = 0x9933ff self.scheduler = AsyncIOScheduler() + self.log = logging.getLogger("cobot.giveaways") async def cog_load(self): """Start the scheduler on cog load""" @@ -60,7 +62,7 @@ async def schedule_giveaways(self): date_treshold = now + timedelta(minutes=5) async for giveaway in self.bot.fb.get_active_giveaways(): if giveaway["ends_at"] < date_treshold: - self.bot.log.debug(f"[giveaways] Scheduling closing of giveaway {giveaway['id']}") + self.log.debug("Scheduling closing of giveaway %s", giveaway['id']) run_date = max(giveaway["ends_at"], now) self.scheduler.add_job(self.close_giveaway, "date", run_date=run_date, args=[giveaway]) @@ -265,7 +267,7 @@ async def close_giveaway(self, data: GiveawayData): "Close a giveaway and pick the winners" if data["ended"]: return - self.bot.log.info(f"[giveaways] Closing giveaway {data['id']}") + self.log.info("Closing giveaway %s", data['id']) message = await self.fetch_gaw_message(data) if message is None: return diff --git a/start.py b/start.py index 2283922..df454e0 100644 --- a/start.py +++ b/start.py @@ -22,7 +22,7 @@ def check_libs(): import discord import asyncio -from src.boot_utils import load_cogs, setup_start_parser +from src.boot_utils import load_cogs, setup_logger, setup_start_parser from src.cobot import CObot @@ -33,6 +33,8 @@ async def main(): if not isinstance(args.beta, bool): raise TypeError("Beta argument must be a boolean") + setup_logger() + client = CObot(status=discord.Status.online, beta=args.beta) client.log.info("Starting bot")