chore: add verbose WS logging to both bot plugins

Log each phase: thread start, TCP connect, subscribe sent, message
received (type), status updates with client list, connection closed
reasons, connection refused/timeout as distinct warnings.

Made-with: Cursor

plugins/limnoria/NtrPlaylist/plugin.py

@@ -139,6 +139,7 @@ class NtrPlaylist(callbacks.Plugin):
 
         backoff = 5
         max_backoff = 60
+        LOGGER.info("WS listener thread started")
 
         while not self._ws_stop.is_set():
             ws_url = self.registryValue("wsUrl")
@@ -151,17 +152,20 @@ class NtrPlaylist(callbacks.Plugin):
                 self._ws_stop.wait(30)
                 continue
 
+            LOGGER.info("Connecting to %s as client_id=%s", ws_url, client_id)
             ws = None
             try:
                 ws = websocket.WebSocket()
                 ws.connect(ws_url, timeout=10)
-                ws.send(json.dumps({
+                LOGGER.info("WebSocket TCP connection established")
+                subscribe_msg = {
                     "type": "subscribe",
                     "token": token,
                     "role": "bot",
                     "client_id": client_id,
-                }))
+                }
-                LOGGER.info("Connected to announce WebSocket at %s", ws_url)
+                ws.send(json.dumps(subscribe_msg))
+                LOGGER.info("Sent subscribe message (role=bot, client_id=%s)", client_id)
                 backoff = 5
 
                 while not self._ws_stop.is_set():
@@ -169,22 +173,36 @@ class NtrPlaylist(callbacks.Plugin):
                     try:
                         raw = ws.recv()
                         if not raw:
+                            LOGGER.warning("Received empty message, connection closing")
                             break
                         data = json.loads(raw)
+                        LOGGER.debug("Received WS message: type=%s", data.get("type"))
                         if data.get("type") == "announce" and "message" in data:
                             msg = ircmsgs.privmsg(channel, data["message"])
                             self._irc.queueMsg(msg)
                             LOGGER.info("Announced to %s: %s", channel, data["message"])
+                        elif data.get("type") == "status":
+                            LOGGER.info(
+                                "Status update: %d bot(s) connected, clients=%s",
+                                data.get("subscribers", 0),
+                                [c.get("client_id") for c in data.get("clients", [])],
+                            )
                     except websocket.WebSocketTimeoutException:
                         continue
                     except websocket.WebSocketConnectionClosedException:
+                        LOGGER.warning("WebSocket connection closed by server")
                         break
+            except ConnectionRefusedError:
+                LOGGER.warning("Connection refused at %s", ws_url)
+            except TimeoutError:
+                LOGGER.warning("Connection timed out to %s", ws_url)
             except Exception:
                 LOGGER.exception("WS listener error")
             finally:
                 if ws:
                     try:
                         ws.close()
+                        LOGGER.debug("WebSocket closed cleanly")
                     except Exception:
                         pass
 

plugins/sopel/ntr_playlist.py

@@ -50,6 +50,7 @@ def _ws_listener(bot):
 
     backoff = 5
     max_backoff = 60
+    LOGGER.info("WS listener thread started")
 
     while not _ws_stop.is_set():
         ws_url = bot.settings.ntr_playlist.ws_url
@@ -62,17 +63,20 @@ def _ws_listener(bot):
             _ws_stop.wait(30)
             continue
 
+        LOGGER.info("Connecting to %s as client_id=%s", ws_url, client_id)
         ws = None
         try:
             ws = websocket.WebSocket()
             ws.connect(ws_url, timeout=10)
-            ws.send(json.dumps({
+            LOGGER.info("WebSocket TCP connection established")
+            subscribe_msg = {
                 "type": "subscribe",
                 "token": token,
                 "role": "bot",
                 "client_id": client_id,
-            }))
+            }
-            LOGGER.info("Connected to announce WebSocket at %s", ws_url)
+            ws.send(json.dumps(subscribe_msg))
+            LOGGER.info("Sent subscribe message (role=bot, client_id=%s)", client_id)
             backoff = 5
 
             while not _ws_stop.is_set():
@@ -80,21 +84,35 @@ def _ws_listener(bot):
                 try:
                     raw = ws.recv()
                     if not raw:
+                        LOGGER.warning("Received empty message, connection closing")
                         break
                     data = json.loads(raw)
+                    LOGGER.debug("Received WS message: type=%s", data.get("type"))
                     if data.get("type") == "announce" and "message" in data:
                         bot.say(data["message"], channel)
                         LOGGER.info("Announced to %s: %s", channel, data["message"])
+                    elif data.get("type") == "status":
+                        LOGGER.info(
+                            "Status update: %d bot(s) connected, clients=%s",
+                            data.get("subscribers", 0),
+                            [c.get("client_id") for c in data.get("clients", [])],
+                        )
                 except websocket.WebSocketTimeoutException:
                     continue
                 except websocket.WebSocketConnectionClosedException:
+                    LOGGER.warning("WebSocket connection closed by server")
                     break
+        except ConnectionRefusedError:
+            LOGGER.warning("Connection refused at %s", ws_url)
+        except TimeoutError:
+            LOGGER.warning("Connection timed out to %s", ws_url)
         except Exception:
             LOGGER.exception("WS listener error")
         finally:
             if ws:
                 try:
                     ws.close()
+                    LOGGER.debug("WebSocket closed cleanly")
                 except Exception:
                     pass