diff --git a/.vscode/launch.json b/.vscode/launch.json index a4eac0e..ceeb788 100644 --- a/.vscode/launch.json +++ b/.vscode/launch.json @@ -29,5 +29,14 @@ "console": "integratedTerminal", "justMyCode": false }, + { + "name": "Run App (DEBUG+WS)", + "type": "python", + "request": "launch", + "program": "main.py", + "args": ["-vvv", "--debug-ws"], + "console": "integratedTerminal", + "justMyCode": false + }, ] -} \ No newline at end of file +} diff --git a/constants.py b/constants.py index 17ba587..454eada 100644 --- a/constants.py +++ b/constants.py @@ -1,6 +1,5 @@ from __future__ import annotations -import logging from copy import copy from datetime import timedelta from typing import Any, Optional, Union, Dict, Callable @@ -9,7 +8,6 @@ from typing import Any, Optional, Union, Dict, Callable JsonType = Dict[str, Any] TopicProcess = Callable[[JsonType], Any] # Values -DEBUG_RAW = logging.DEBUG - 1 MAX_WEBSOCKETS = 8 WS_TOPICS_LIMIT = 50 # URLs diff --git a/main.py b/main.py index 2de0641..a4ed033 100644 --- a/main.py +++ b/main.py @@ -7,13 +7,14 @@ import json import ctypes import logging import asyncio +import argparse import warnings import traceback import threading -from typing import NoReturn +from typing import Literal, NoReturn from twitch import Twitch -from constants import JsonType, SETTINGS_PATH, TERMINATED_STR, DEBUG_RAW +from constants import JsonType, SETTINGS_PATH, TERMINATED_STR try: import win32api @@ -41,29 +42,55 @@ def terminate() -> NoReturn: raise RuntimeError("Uh oh") # this will never run, solely for MyPy -# extra debug logging level -logging.addLevelName(DEBUG_RAW, "DEBUG_RAW") -# handle extra stackable '-v' parameter, that switches the logging level -logging_level = logging.ERROR -if len(sys.argv) > 1: - arg = sys.argv[1] - if arg == ("-v", "-v1"): - logging_level = logging.WARNING - elif arg in ("-vv", "-v2"): - logging_level = logging.INFO - elif arg in ("-vvv", "-v3"): - logging_level = logging.DEBUG - elif arg in ("-vvvv", "-v4"): - # enables debugging raw messages - logging_level = DEBUG_RAW +class ParsedArgs(argparse.Namespace): + _verbose: int + debug_ws: Literal[Literal[0], Literal[10]] + debug_gql: Literal[Literal[0], Literal[10]] + + @property + def logging_level(self) -> int: + return { + 0: logging.ERROR, + 1: logging.WARNING, + 2: logging.INFO, + 3: logging.DEBUG, + }.get(self._verbose, logging.DEBUG) + + +# handle input parameters +parser = argparse.ArgumentParser( + f"TwitchDropsMiner.v{__version__}.exe", + description="A program that allows you to mine timed drops on Twitch.", +) +parser.add_argument("-V", "--version", action="version", version=f"v{__version__}") +parser.add_argument("-v", dest="_verbose", action="count", default=0) +parser.add_argument( + "--debug-ws", + dest="debug_ws", + action="store_const", + const=logging.DEBUG, + default=logging.NOTSET, +) +parser.add_argument( + "--debug-gql", + dest="debug_gql", + action="store_const", + const=logging.DEBUG, + default=logging.NOTSET, +) +options: ParsedArgs = parser.parse_args(namespace=ParsedArgs()) # handle logging stuff -root_logger = logging.getLogger() -root_logger.addHandler(logging.NullHandler()) +if options.logging_level > logging.DEBUG: + # redirect the root logger into a NullHandler, effectively ignoring all logging calls + # that aren't ours. This always runs, unless the main logging level is DEBUG or below. + logging.getLogger().addHandler(logging.NullHandler()) logger = logging.getLogger("TwitchDrops") handler = logging.StreamHandler(sys.stdout) handler.setFormatter(logging.Formatter("{levelname}: {message}", style='{')) logger.addHandler(handler) -logger.setLevel(logging_level) +logger.setLevel(options.logging_level) +logging.getLogger("TwitchDrops.gql").setLevel(options.debug_gql) +logging.getLogger("TwitchDrops.websocket").setLevel(options.debug_ws) # handle settings try: with open(SETTINGS_PATH, 'r', encoding="utf8") as file: diff --git a/twitch.py b/twitch.py index 8776935..9a7beb7 100644 --- a/twitch.py +++ b/twitch.py @@ -21,7 +21,6 @@ from constants import ( JsonType, WebsocketTopic, CLIENT_ID, - DEBUG_RAW, USER_AGENT, COOKIES_PATH, AUTH_URL, @@ -34,6 +33,7 @@ from constants import ( logger = logging.getLogger("TwitchDrops") +gql_logger = logging.getLogger("TwitchDrops.gql") class Twitch: @@ -417,10 +417,10 @@ class Twitch: "Authorization": f"OAuth {self._access_token}", "Client-Id": CLIENT_ID, } - logger.log(DEBUG_RAW, f"GQL Request: {op}") + gql_logger.debug(f"GQL Request: {op}") async with self._session.post(GQL_URL, json=op, headers=headers) as response: response_json = await response.json() - logger.log(DEBUG_RAW, f"GQL Response: {response_json}") + gql_logger.debug(f"GQL Response: {response_json}") return response_json async def get_inventory(self) -> List[DropsCampaign]: diff --git a/websocket.py b/websocket.py index 9a3afee..d875ef2 100644 --- a/websocket.py +++ b/websocket.py @@ -18,7 +18,6 @@ from exceptions import MinerException from constants import ( JsonType, WebsocketTopic, - DEBUG_RAW, WEBSOCKET_URL, PING_INTERVAL, MAX_WEBSOCKETS, @@ -29,7 +28,7 @@ if TYPE_CHECKING: from twitch import Twitch -logger = logging.getLogger("TwitchDrops") +ws_logger = logging.getLogger("TwitchDrops.websocket") NONCE_CHARS = string.ascii_letters + string.digits @@ -43,7 +42,7 @@ def task_wrapper(afunc): try: await afunc(self, *args, **kwargs) except Exception: - logger.exception("Exception in websocket task") + ws_logger.exception("Exception in websocket task") raise # raise up to the wrapping task return wrapper @@ -79,6 +78,7 @@ class Websocket: return self._connected_flag.wait() def request_reconnect(self): + ws_logger.warning(f"Websocket[{self._idx}] requested reconnect.") self._reconnect_requested.set() async def start(self): @@ -114,7 +114,7 @@ class Websocket: async def _handle(self): # ensure we're logged in before connecting await self._twitch.wait_until_login() - logger.info("Connecting to Websocket") + ws_logger.info(f"Websocket[{self._idx}] connecting...") # Connect/Reconnect loop async for websocket in websocket_connect(WEBSOCKET_URL, ssl=True, ping_interval=None): websocket.BACKOFF_MAX = 3 * 60 # type: ignore # 3 minutes @@ -131,21 +131,25 @@ class Websocket: self._submitted.clear() self._connected_flag.clear() # A reconnect was requested - continue except ConnectionClosed as exc: if isinstance(exc, ConnectionClosedOK): if exc.rcvd_then_sent: # server closed the connection, not us - reconnect - logger.warning("Server Disconnected - Reconnecting") - continue - # we closed it - exit - return - # otherwise, reconnect - logger.warning("Websocket Closed - Reconnecting") - continue + ws_logger.warning(f"Websocket[{self._idx}] disconnected.") + else: + # we closed it - exit + ws_logger.info(f"Websocket[{self._idx}] stopped.") + return + if exc.rcvd is not None: + code = exc.rcvd.code + elif exc.sent is not None: + code = exc.sent.code + else: + code = -1 + ws_logger.warning(f"Websocket[{self._idx}] closed unexpectedly: {code}") except Exception: - logger.exception("Exception in Websocket - Reconnecting") - continue + ws_logger.exception(f"Exception in Websocket[{self._idx}]") + ws_logger.warning(f"Websocket[{self._idx}] reconnecting...") async def _handle_ping(self): now = time() @@ -166,7 +170,7 @@ class Websocket: removed = self._submitted.difference(current) if removed: topics_list = list(map(str, removed)) - logger.debug(f"Websocket[{self._idx}]: Removing topics: {', '.join(topics_list)}") + ws_logger.debug(f"Websocket[{self._idx}]: Removing topics: {', '.join(topics_list)}") await self.send( { "type": "UNLISTEN", @@ -181,7 +185,7 @@ class Websocket: added = current.difference(self._submitted) if added: topics_list = list(map(str, added)) - logger.debug(f"Websocket[{self._idx}]: Adding topics: {', '.join(topics_list)}") + ws_logger.debug(f"Websocket[{self._idx}]: Adding topics: {', '.join(topics_list)}") await self.send( { "type": "LISTEN", @@ -202,7 +206,7 @@ class Websocket: while True: raw_message = await self._ws.recv() message = json.loads(raw_message) - logger.log(DEBUG_RAW, f"Websocket received: {message}") + ws_logger.debug(f"Websocket[{self._idx}] received: {message}") messages.append(message) def _handle_message(self, message): @@ -233,10 +237,9 @@ class Websocket: pass elif msg_type == "RECONNECT": # We've received a reconnect request - logger.warning("Received a Websocket Reconnect Request") self.request_reconnect() else: - logger.error(f"Received unknown websocket payload: {message}") + ws_logger.warning(f"Websocket[{self._idx}] received unknown payload: {message}") def add_topics(self, topics_set: Set[WebsocketTopic]): while topics_set and len(self.topics) < WS_TOPICS_LIMIT: @@ -260,7 +263,7 @@ class Websocket: if message["type"] != "PING": message["nonce"] = create_nonce() await self._ws.send(json.dumps(message, separators=(',', ':'))) - logger.log(DEBUG_RAW, f"Websocket sent: {message}") + ws_logger.debug(f"Websocket[{self._idx}] sent: {message}") class WebsocketPool: @@ -350,7 +353,7 @@ class WebsocketPool: if drop is not None: break else: - logger.error(f"Drop with ID of {drop_id} not found!") + ws_logger.warning(f"Drop with ID of {drop_id} not found!") return drop.update(message) msg_type = message["type"]