yes yes yes

royalnet/backpack/events/play.py

@@ -34,6 +34,7 @@ class PlayEvent(Event):
                     break
         if guild is None:
             raise InvalidInputError("No guild_id or guild_name specified.")
+        log.debug(f"Selected guild: {guild}")
         # Find the bard
         bard: Optional[DiscordBard] = self.serf.bards.get(guild)
         if bard is None:

royalnet/bard/ytdlfile.py

@@ -1,4 +1,5 @@
 import os
+import logging
 from contextlib import asynccontextmanager
 from typing import Optional, List, Dict, Any
 from royalnet.utils import asyncify, MultiLock
@@ -12,6 +13,9 @@ except ImportError:
     youtube_dl = None
 
 
+log = logging.getLogger(__name__)
+
+
 class YtdlFile:
     """A representation of a file download with :mod:`youtube_dl`."""
 
@@ -71,11 +75,13 @@ class YtdlFile:
             """Download function block to be asyncified."""
             with YoutubeDL(self.ytdl_args) as ytdl:
                 filename = ytdl.prepare_filename(self.info.__dict__)
+            with YoutubeDL({**self.ytdl_args, "outtmpl": filename}) as ytdl:
                 ytdl.download([self.info.webpage_url])
                 self.filename = filename
 
         await self.retrieve_info()
         async with self.lock.exclusive():
+            log.debug(f"Downloading with youtube-dl: {self}")
             await asyncify(download, loop=self._loop)
 
     @asynccontextmanager
@@ -91,14 +97,19 @@ class YtdlFile:
         """
         await self.download_file()
         async with self.lock.normal():
+            log.debug(f"File opened: {self.filename}")
             with open(self.filename, "rb") as file:
                 yield file
+            log.debug(f"File closed: {self.filename}")
 
     async def delete_asap(self):
         """As soon as nothing is using the file, delete it."""
-        async with self.lock.exclusive():
-            os.remove(self.filename)
-            self.filename = None
+        log.debug(f"Trying to delete: {self.filename}")
+        if self.filename is not None:
+            async with self.lock.exclusive():
+                os.remove(self.filename)
+                log.debug(f"Deleted: {self.filename}")
+                self.filename = None
 
     @classmethod
     async def from_url(cls, url: str, **ytdl_args) -> List["YtdlFile"]:

royalnet/bard/ytdlinfo.py

@@ -2,6 +2,7 @@ from asyncio import AbstractEventLoop, get_event_loop
 from typing import Optional, Dict, List, Any
 from datetime import datetime, timedelta
 import dateparser
+import logging
 from royalnet.utils import ytdldateformat, asyncify
 
 try:
@@ -10,6 +11,9 @@ except ImportError:
     YoutubeDL = None
 
 
+log = logging.getLogger(__name__)
+
+
 class YtdlInfo:
     """A wrapper around youtube_dl extracted info."""
 
@@ -95,6 +99,7 @@ class YtdlInfo:
         if loop is None:
             loop: AbstractEventLoop = get_event_loop()
         # So many redundant options!
+        log.debug(f"Fetching info: {url}")
         with YoutubeDL({**cls._default_ytdl_args, **ytdl_args}) as ytdl:
             first_info = await asyncify(ytdl.extract_info, loop=loop, url=url, download=False)
         # No video was found
@@ -102,12 +107,14 @@ class YtdlInfo:
             return []
         # If it is a playlist, create multiple videos!
         if "entries" in first_info and first_info["entries"][0] is not None:
+            log.debug(f"Found a playlist: {url}")
             second_info_list = []
             for second_info in first_info["entries"]:
                 if second_info is None:
                     continue
                 second_info_list.append(YtdlInfo(second_info))
             return second_info_list
+        log.debug(f"Found a single video: {url}")
         return [YtdlInfo(first_info)]
 
     def __repr__(self):

royalnet/serf/discord/discordbard/discordbard.py

@@ -50,7 +50,7 @@ class DiscordBard:
         """Get the next :class:`FileAudioSource` that should be played, and change :attr:`.now_playing`.
 
         Args and kwargs can be passed to the generator to select differently."""
-        fas: Optional[FileAudioSource] = await self.generator.asend((args, kwargs))
+        fas: Optional[FileAudioSource] = await self.generator.asend((args, kwargs,))
         self.now_playing = fas
         return fas
 

royalnet/serf/discord/discordbard/ytdldiscord.py

@@ -1,6 +1,7 @@
 import typing
 import re
 import os
+import logging
 from contextlib import asynccontextmanager
 from royalnet.utils import asyncify, MultiLock
 from royalnet.bard import YtdlInfo, YtdlFile
@@ -16,6 +17,9 @@ except ImportError:
     ffmpeg = None
 
 
+log = logging.getLogger(__name__)
+
+
 class YtdlDiscord:
     """A representation of a YtdlFile conversion to the :mod:`discord` PCM format."""
     def __init__(self, ytdl_file: YtdlFile):
@@ -37,6 +41,7 @@ class YtdlDiscord:
             async with self.ytdl_file.lock.normal():
                 destination_filename = re.sub(r"\.[^.]+$", ".pcm", self.ytdl_file.filename)
                 async with self.lock.exclusive():
+                    log.debug(f"Converting to PCM: {self.ytdl_file.filename}")
                     await asyncify(
                         ffmpeg.input(self.ytdl_file.filename)
                               .output(destination_filename, format="s16le", ac=2, ar="48000")
@@ -47,9 +52,11 @@ class YtdlDiscord:
 
     async def delete_asap(self) -> None:
         """Delete the mp3 file."""
+        log.debug(f"Trying to delete: {self}")
         if self.is_converted:
             async with self.lock.exclusive():
                 os.remove(self.pcm_filename)
+                log.debug(f"Deleted: {self.pcm_filename}")
                 self.pcm_filename = None
 
     @classmethod
@@ -69,6 +76,7 @@ class YtdlDiscord:
 
     @asynccontextmanager
     async def spawn_audiosource(self):
+        log.debug(f"Spawning audio_source for: {self}")
         if FileAudioSource is None:
             raise ImportError("'discord' extra is not installed")
         await self.convert_to_pcm()

royalnet/utils/multilock.py

@@ -1,5 +1,9 @@
 from asyncio import Event
 from contextlib import asynccontextmanager
+import logging
+
+
+log = logging.getLogger(__name__)
 
 
 class MultiLock:
@@ -8,6 +12,7 @@ class MultiLock:
         self._counter: int = 0
         self._normal_event: Event = Event()
         self._exclusive_event: Event = Event()
+        self._normal_event.set()
         self._exclusive_event.set()
 
     def _check_event(self):
@@ -19,23 +24,35 @@ class MultiLock:
     @asynccontextmanager
     async def normal(self):
         """Acquire the lock for simultaneous access."""
+        log.debug(f"Waiting for exclusive lock end: {self}")
         await self._exclusive_event.wait()
+        log.debug(f"Acquiring normal lock: {self}")
         self._counter += 1
         self._check_event()
         try:
             yield
         finally:
+            log.debug(f"Releasing normal lock: {self}")
             self._counter -= 1
             self._check_event()
 
     @asynccontextmanager
     async def exclusive(self):
         """Acquire the lock for exclusive access."""
+        log.debug(f"Waiting for exclusive lock end: {self}")
         # TODO: check if this actually works
         await self._exclusive_event.wait()
         self._exclusive_event.clear()
+        log.debug(f"Waiting for normal lock end: {self}")
         await self._normal_event.wait()
         try:
+            log.debug("Acquiring exclusive lock: {self}")
+            self._exclusive_event.clear()
             yield
         finally:
+            log.debug("Releasing exclusive lock: {self}")
             self._exclusive_event.set()
+
+    def __repr__(self):
+        return f"<MultiLock {self._counter} " \
+               f"{'N' if self._normal_event.is_set() else '_'}{'E' if self._exclusive_event.is_set() else '_'}>"