From c11c87ccae567c5c1d5c7f9fe185f52ae7390caa Mon Sep 17 00:00:00 2001
From: ekzyis <ramdip.singhgill@gmail.com>
Date: Thu, 4 Nov 2021 01:43:52 +0100
Subject: [PATCH] Add more INFO logging

---
 src/bot.py | 11 +++++++++++
 1 file changed, 11 insertions(+)

diff --git a/src/bot.py b/src/bot.py
index 16e1320..1d4ee36 100644
--- a/src/bot.py
+++ b/src/bot.py
@@ -70,6 +70,7 @@ class Music(commands.Cog):
 
   def _next(self):
     """Trigger playback of next song."""
+    self.logger.info("Song finished. Triggering playback of next song")
     self._queue.task_done()
     self._current_skip_message = None
     if self._queue_lock.locked():
@@ -79,12 +80,16 @@ class Music(commands.Cog):
   async def _handle_playback(self):
     while True:
       try:
+        self.logger.info("Waiting for queue lock to acquire ...")
         await self._queue_lock.acquire()
+        self.logger.info("Queue lock acquired! Waiting for song queue to return a song ...")
         ctx, song = await self._queue.get()
+        self.logger.info("Queue returned a song!")
         if ctx.voice_client is None:
           # Bot is no longer in a voice channel.
           # This could be the case because a stop command was issued.
           # We will skip this (and possibly all remaining songs) in the queue
+          self.logger.info('Bot is no longer in a voice channel. Skipping song "%s".', song.title)
           self._next()
           continue
         audio = discord.FFmpegPCMAudio(song.audio_url, **self._ffmpeg_options)
@@ -93,6 +98,7 @@ class Music(commands.Cog):
           if err:
             self.logger.error("Player error: %s", err)
           self._next()
+        self.logger.info('Now playing song "%s"', song.title)
         ctx.voice_client.play(audio, after=after)
         embed = NowPlayingMessage(title=song.title, url=song.webpage_url)
         msg = await ctx.send(embed=embed)
@@ -133,6 +139,7 @@ class Music(commands.Cog):
             audio_url=data.get('url'),
             webpage_url=data.get('webpage_url')
         )
+        self.logger.info('Qeueing song: title="%s", audio_url=%s, webpage_url=%s', song.title, song.audio_url, song.webpage_url)
         await self._queue.put((ctx, song))
         if ctx.voice_client.is_playing():
           embed = QueuedMessage(title=song.title, url=song.webpage_url)
@@ -144,6 +151,7 @@ class Music(commands.Cog):
       raise commands.CommandError("No song playing")
     # This skips to next song because the bot does not differentiate between
     # a song stopping because it is finished or because it was manually stopped.
+    self.logger.info("Skipping song")
     voice_client.stop()
 
   @commands.command()
@@ -153,13 +161,16 @@ class Music(commands.Cog):
 
   @commands.command()
   async def stop(self, ctx):
+    self.logger.info("Stopping playback")
     await ctx.voice_client.disconnect()
 
   @play.before_invoke
   async def ensure_voice(self, ctx):
     if ctx.voice_client is None:
       if ctx.author.voice:
+        self.logger.info("Connecting to voice channel ...")
         await ctx.author.voice.channel.connect()
+        self.logger.info("Connected")
       else:
         raise commands.CommandError("Author not connected to a voice channel")