From 4e989bfd9bf56c428e0266c151dd48dde594cf2a Mon Sep 17 00:00:00 2001
From: SeaswimmerTheFsh <seaswimmerthefsh@gmail.com>
Date: Mon, 1 Jan 2024 12:14:53 -0500
Subject: [PATCH] fix(aurora): fixed logging and added a debug logger for
 tracking performance in handle_expiry

---
 aurora/aurora.py | 18 +++++++++++++-----
 1 file changed, 13 insertions(+), 5 deletions(-)

diff --git a/aurora/aurora.py b/aurora/aurora.py
index 3ac645b..5534841 100644
--- a/aurora/aurora.py
+++ b/aurora/aurora.py
@@ -430,9 +430,9 @@ class Aurora(commands.Cog):
             return
 
         if delete_messages is None:
-            delete_messages = 0
+            delete_messages_seconds = 0
         else:
-            delete_messages = delete_messages.value
+            delete_message_seconds = delete_messages.value
 
         try:
             await interaction.guild.fetch_ban(target)
@@ -456,7 +456,7 @@ class Aurora(commands.Cog):
             except discord.errors.HTTPException:
                 pass
 
-            await interaction.guild.ban(target, reason=f"Tempbanned by {interaction.user.id} for: {reason} (Duration: {parsed_time})", delete_message_seconds=delete_messages)
+            await interaction.guild.ban(target, reason=f"Tempbanned by {interaction.user.id} for: {reason} (Duration: {parsed_time})", delete_message_seconds=delete_messages_seconds)
 
             moderation_id = await mysql_log(interaction.guild.id, interaction.user.id, 'TEMPBAN', 'USER', target.id, 0, parsed_time, reason)
             await interaction.edit_original_response(content=f"{target.mention} has been banned for {humanize.precisedelta(parsed_time)}! (Case `#{moderation_id}`)\n**Reason** - `{reason}`")
@@ -476,7 +476,7 @@ class Aurora(commands.Cog):
                 except discord.errors.HTTPException:
                     pass
 
-            await interaction.guild.ban(target, reason=f"Banned by {interaction.user.id} for: {reason}", delete_message_seconds=delete_messages)
+            await interaction.guild.ban(target, reason=f"Banned by {interaction.user.id} for: {reason}", delete_message_seconds=delete_messages_seconds)
 
             moderation_id = await mysql_log(interaction.guild.id, interaction.user.id, 'BAN', 'USER', target.id, 0, 'NULL', reason)
             await interaction.edit_original_response(content=f"{target.mention} has been banned! (Case `#{moderation_id:,}`)\n**Reason** - `{reason}`")
@@ -943,12 +943,14 @@ class Aurora(commands.Cog):
 
     @tasks.loop(minutes=1)
     async def handle_expiry(self):
+        current_time = time.time()
         database = connect()
         cursor = database.cursor()
 
         guilds: list[discord.Guild] = self.bot.guilds
         for guild in guilds:
             if not await self.bot.cog_disabled_in_guild(self, guild):
+                time_per_guild = time.time()
 
                 tempban_query = f"SELECT target_id, moderation_id FROM moderation_{guild.id} WHERE end_timestamp != 0 AND end_timestamp <= ? AND moderation_type = 'TEMPBAN' AND expired = 0"
 
@@ -973,7 +975,7 @@ class Aurora(commands.Cog):
                         except discord.errors.HTTPException:
                             pass
                     except [discord.errors.NotFound, discord.errors.Forbidden, discord.errors.HTTPException] as e:
-                        print(f"Failed to unban {user.name}#{user.discriminator} ({user.id}) from {guild.name} ({guild.id})\n{e}")
+                        logger.error("Failed to unban %s#%s (%s) from %s (%s)\n%s", user.name, user.discriminator, user.id, guild.name, guild.id, e)
 
                 expiry_query = f"UPDATE `moderation_{guild.id}` SET expired = 1 WHERE (end_timestamp != 0 AND end_timestamp <= ? AND expired = 0 AND moderation_type != 'BLACKLIST') OR (expired = 0 AND resolved = 1  AND moderation_type != 'BLACKLIST')"
                 cursor.execute(expiry_query, (time.time(),))
@@ -998,10 +1000,16 @@ class Aurora(commands.Cog):
                     except [discord.errors.NotFound, discord.errors.Forbidden, discord.errors.HTTPException]:
                         continue
 
+                per_guild_completion_time = (time.time() - time_per_guild) * 1000
+                logger.debug("Completed expiry loop for %s (%s) in %sms", guild.name, guild.id, f"{per_guild_completion_time:.6f}")
+
         database.commit()
         cursor.close()
         database.close()
 
+        completion_time = (time.time() - current_time) * 1000
+        logger.debug("Completed expiry loop in %sms", f"{completion_time:.6f}")
+
     #######################################################################################################################
     ### CONFIGURATION COMMANDS
     #######################################################################################################################