feat(log): rewrite logging handlers

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"

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):

src/firebase/client.py

@@ -18,15 +18,15 @@ 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"
         if self.cache.are_giveaways_sync:
             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)

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:

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("```"):

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

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")