More logging

syng/client.py

@@ -346,8 +346,14 @@ class Client:
             if entry.ident in source.downloaded_files:
                 continue
             logger.info("Buffering: %s (%d s)", entry.title, entry.duration)
+            started = datetime.datetime.now()
             try:
                 await self.sources[entry.source].buffer(entry, pos)
+                logger.info(
+                    "Buffered %s in %d seconds",
+                    entry.title,
+                    (datetime.datetime.now() - started).seconds,
+                )
             except ValueError as e:
                 logger.error("Error buffering: %s", e)
                 await self.sio.emit("skip", {"uuid": entry.uuid})
@@ -450,6 +456,14 @@ class Client:
             f"Playing: {entry.artist} - {entry.title} [{entry.album}] "
             f"({entry.source}) for {entry.performer}"
         )
+        logger.info(
+            "Playing: %s - %s [%s] (%s) for %s",
+            entry.artist,
+            entry.title,
+            entry.album,
+            entry.source,
+            entry.performer,
+        )
         if entry.uuid not in self.skipped:
             try:
                 if self.state.config["preview_duration"] > 0:
@@ -486,6 +500,7 @@ class Client:
         :type data: dict[str, Any]
         :rtype: None
         """
+        logger.debug("Handling search: %s (%s)", data["query"], data["search_id"])
         query = data["query"]
         sid = data["sid"]
         search_id = data["search_id"]
@@ -498,6 +513,7 @@ class Client:
             for source_result in results_list
             for search_result in source_result
         ]
+        logger.debug("Search results: %d results", len(results))
 
         await self.sio.emit(
             "search-results", {"results": results, "sid": sid, "search_id": search_id}

syng/server.py

@@ -642,6 +642,7 @@ class Server:
             )
             return None
 
+        logger.debug(f"Appending {entry} to queue in room {state.sid}")
         entry.uid = data["uid"] if "uid" in data else None
 
         await self.append_to_queue(state, entry, sid)
@@ -1351,7 +1352,7 @@ class Server:
         if room in self.clients:
             old_state: State = self.clients[room]
             if data["config"]["secret"] == old_state.client.config["secret"]:
-                logger.info("Got new client connection for %s", room)
+                logger.info("Got new playback client connection for %s", room)
                 old_state.sid = sid
                 old_state.client = Client(
                     sources=old_state.client.sources,
@@ -1364,7 +1365,7 @@ class Server:
                 logger.warning("Got wrong secret for %s", room)
                 raise ConnectionRefusedError(f"Wrong secret for room {room}.")
         else:
-            logger.info("Registerd new client %s", room)
+            logger.info("Registerd new playback client %s", room)
             initial_entries = [Entry(**entry) for entry in data["queue"]]
             initial_waiting_room = [Entry(**entry) for entry in data["waiting_room"]]
             initial_recent = [Entry(**entry) for entry in data["recent"]]