From 68621aa5f3801304bd2b0e81c1df7f2bc024ebca Mon Sep 17 00:00:00 2001 From: ooliver1 Date: Sat, 17 Sep 2022 22:53:20 +0100 Subject: [PATCH] feat: absolutely flood with logging calls --- mafic/node.py | 74 +++++++++++++++++++++++++++++++++++++++++-------- mafic/player.py | 8 ++++++ mafic/pool.py | 5 ++++ 3 files changed, 76 insertions(+), 11 deletions(-) diff --git a/mafic/node.py b/mafic/node.py index 35219d9..3b01b50 100644 --- a/mafic/node.py +++ b/mafic/node.py @@ -55,7 +55,6 @@ def __init__( self._ws_task: Task[None] | None = None self._available = False - self._backoff = ExponentialBackoff() self.players: dict[int, Player] = {} @@ -80,6 +79,7 @@ def secure(self) -> bool: return self._secure async def connect(self) -> None: + _log.info("Waiting for client to be ready...", extra={"label": self._label}) await self._client.wait_until_ready() assert self._client.user is not None @@ -95,45 +95,84 @@ async def connect(self) -> None: "Resume-Key": self._resume_key, } + _log.info( + "Connecting to lavalink at %s...", + self._rest_uri, + extra={"label": self._label}, + ) self._ws = await session.ws_connect( # pyright: ignore[reportUnknownMemberType] self._ws_uri, timeout=self._timeout, heartbeat=self._heartbeat, headers=headers, ) + _log.info("Connected to lavalink.", extra={"label": self._label}) + _log.debug( + "Creating task to send configuration to resume with key %s", + self._resume_key, + extra={"label": self._label}, + ) + create_task(self.send_resume_configuration()) + + _log.info( + "Creating task for websocket listener...", extra={"label": self._label} + ) self._ws_task = create_task( self._ws_listener(), name=f"mafic node {self._label}" ) + _log.info( + "Node %s is now available.", self._label, extra={"label": self._label} + ) self._available = True - await sleep(1) - if self._available: - self._backoff = ExponentialBackoff() - async def _ws_listener(self) -> None: + backoff = ExponentialBackoff() + if self._ws is None: + _log.error( + "No websocket was found, aborting listener.", + extra={"label": self._label}, + ) raise RuntimeError( "Websocket is not connected but attempted to listen, report this." ) - async for message in self._ws: + # To catch closing messages, we cannot use async for. + while True: + msg = await self._ws.receive() + + _log.debug("Received message from websocket.", extra={"label": self._label}) + # Please aiohttp, fix your typehints. - _type: WSMsgType = message.type # pyright: ignore[reportUnknownMemberType] + _type: WSMsgType = msg.type # pyright: ignore[reportUnknownMemberType] if _type is WSMsgType.CLOSED: self._available = False + close_code = self._ws.close_code self._ws = None - wait_time = self._backoff.delay() - _log.warning("Websocket closed, reconnecting in %.2f...", wait_time) + wait_time = backoff.delay() + _log.warn( + "Websocket was closed from host %s port %s with RFC 6455 code %s. " + "Reconnecting in %.2fs", + self._host, + self._port, + close_code, + wait_time, + extra={"label": self._label}, + ) await sleep(wait_time) create_task(self.connect()) return else: - create_task(self._handle_msg(message.json(loads=loads))) + _log.debug( + "Creating task to handle websocket message.", + extra={"label": self._label}, + ) + create_task(self._handle_msg(msg.json(loads=loads))) async def __send(self, data: OutgoingMessage) -> None: if self._ws is None: @@ -141,6 +180,7 @@ async def __send(self, data: OutgoingMessage) -> None: "Websocket is not connected but attempted to send, report this." ) + _log.debug("Sending message to websocket.", extra={"label": self._label}) await self._ws.send_json(data, dumps=dumps) async def _handle_msg(self, data: IncomingMessage) -> None: @@ -164,7 +204,7 @@ async def _handle_msg(self, data: IncomingMessage) -> None: else: # Of course pyright considers this to be `Never`, so this is to keep types. op = cast(str, data["op"]) - _log.warn("Unknown incoming op code %s", op) + _log.warn("Unknown incoming message op code %s", op) async def _handle_event(self, data: EventPayload) -> None: if data["type"] == "WebSocketClosedEvent": @@ -192,6 +232,12 @@ async def _handle_event(self, data: EventPayload) -> None: def send_voice_server_update( self, guild_id: int, session_id: str, data: VoiceServerUpdatePayload ) -> Coro[None]: + _log.debug( + "Sending voice server update to lavalink with data %s.", + data, + extra={"label": self._label, "guild": guild_id}, + ) + return self.__send( { "op": "voiceUpdate", @@ -202,6 +248,12 @@ def send_voice_server_update( ) def send_resume_configuration(self) -> Coro[None]: + _log.info( + "Sending resume configuration to lavalink with resume key %s.", + self._resume_key, + extra={"label": self._label}, + ) + return self.__send( { "op": "configureResuming", diff --git a/mafic/player.py b/mafic/player.py index f1c1187..08b9c5d 100644 --- a/mafic/player.py +++ b/mafic/player.py @@ -2,6 +2,7 @@ from __future__ import annotations +from logging import getLogger from typing import TYPE_CHECKING from .__libraries import VoiceProtocol @@ -18,6 +19,9 @@ from .node import Node +_log = getLogger(__name__) + + class Player(VoiceProtocol): def __init__( self, @@ -39,6 +43,7 @@ async def on_voice_state_update(self, data: GuildVoiceStatePayload) -> None: async def on_voice_server_update(self, data: VoiceServerUpdatePayload) -> None: if self._node is None: + _log.debug("Getting best node for player", extra={"guild": self._guild_id}) self._node = NodePool.get_node( guild_id=data["guild_id"], endpoint=data["endpoint"] ) @@ -46,6 +51,7 @@ async def on_voice_server_update(self, data: VoiceServerUpdatePayload) -> None: self._server_state = data if self._guild_id is None or self._session_id is None: + _log.warn("Ignoring voice server update as guild and session are unknown.") return await self._node.send_voice_server_update( @@ -63,6 +69,8 @@ async def connect( if not isinstance(self.channel, GuildChannel): raise TypeError("Voice channel must be a GuildChannel.") + _log.debug("Connecting to voice channel %s", self.channel.id) + await self.channel.guild.change_voice_state( channel=self.channel, self_mute=self_mute, self_deaf=self_deaf ) diff --git a/mafic/pool.py b/mafic/pool.py index 37987b3..c6266b7 100644 --- a/mafic/pool.py +++ b/mafic/pool.py @@ -2,6 +2,7 @@ from __future__ import annotations +from logging import getLogger from random import choice from typing import TYPE_CHECKING @@ -15,6 +16,9 @@ from .__libraries import Client +_log = getLogger(__name__) + + class NodePool: _nodes: ClassVar[dict[str, Node]] = {} @@ -53,6 +57,7 @@ async def create_node( # TODO: assign dicts for regions and such cls._nodes[label] = node + _log.info("Created node, connecting it...", extra={"label": label}) await node.connect() return node