From 63e4f5af57f46d42a6f2fb85a87b82e78bca9e22 Mon Sep 17 00:00:00 2001 From: Jacob Henry Date: Sun, 10 Mar 2019 01:12:56 -0500 Subject: [PATCH] Improved logging --- .gitignore | 1 + client.py | 22 ++++++++++------------ hooks.py | 3 ++- main.py | 7 ++++++- plugins/job_commands.py | 3 ++- plugins/periodicals.py | 7 ++++--- settings.py | 11 +++++++++++ slack_util.py | 22 +++++++++------------- 8 files changed, 45 insertions(+), 31 deletions(-) create mode 100644 settings.py diff --git a/.gitignore b/.gitignore index d0a67c2..c1042af 100644 --- a/.gitignore +++ b/.gitignore @@ -7,6 +7,7 @@ sheets_token.json *.dir *.pyc *.swp +*.log script_log.txt towels_rolled user_scrolls \ No newline at end of file diff --git a/client.py b/client.py index 923d54b..4abecd2 100644 --- a/client.py +++ b/client.py @@ -4,7 +4,8 @@ import asyncio import json import sys import traceback -from pprint import pprint +import logging +from pprint import pformat from typing import List, Any, AsyncGenerator, Dict, Coroutine, TypeVar from typing import Optional @@ -14,9 +15,6 @@ from slackclient import SlackClient import hooks import slack_util -# Enable to do single-threaded and have better exceptions -DEBUG_MODE = False - """ Objects to wrap slack connections """ @@ -81,7 +79,7 @@ class ClientWrapper(object): async def handle_task_loop(): async for t3 in self.spool_tasks(queue): sys.stdout.flush() - if DEBUG_MODE: + if settings.SINGLE_THREAD_TASKS: await t3 # Handle them all @@ -111,8 +109,8 @@ class ClientWrapper(object): # Get the payload post_params = await request.post() payload = json.loads(post_params["payload"]) - print("\nInteraction Event received:") - pprint(payload) + logging.info("\nInteraction Event received:") + logging.debug(pformat(payload)) # Handle each action separately if "actions" in payload: @@ -142,7 +140,7 @@ class ClientWrapper(object): # Respond that everything is fine return web.Response(status=200) else: - print("\nMalformed event received.") + logging.error("\nMalformed event received.") # If we can't read it, get mad return web.Response(status=400) @@ -155,7 +153,7 @@ class ClientWrapper(object): await runner.setup() site = web.TCPSite(runner, port=31019) await site.start() - print("Server up") + logging.info("Server up") # while True: # await asyncio.sleep(30) @@ -174,7 +172,7 @@ class ClientWrapper(object): # If we get a coro back, then task it up and set consumption appropriately if coro is not None: - print("Spawned task. Now {} running total.".format(len(asyncio.all_tasks()))) + log.debug("Spawned task. Now {} running total.".format(len(asyncio.all_tasks()))) yield asyncio.create_task(_exception_printing_task(coro)) if hook.consumes: break @@ -351,7 +349,7 @@ class ClientWrapper(object): break else: - print("Warning: failed to retrieve channels. Message: {}".format(channel_dicts)) + logging.warning("Failed to retrieve channels. Message: {}".format(channel_dicts)) break self.conversations = new_dict @@ -390,7 +388,7 @@ class ClientWrapper(object): break else: - print("Warning: failed to retrieve users") + logging.warning("Warning: failed to retrieve users") break self.users = new_dict diff --git a/hooks.py b/hooks.py index 3e30cf5..040180d 100644 --- a/hooks.py +++ b/hooks.py @@ -1,5 +1,6 @@ from __future__ import annotations +import logging import re from time import time from typing import Match, Any, Coroutine, Callable, Optional, Union, List, TypeVar, Dict @@ -204,7 +205,7 @@ class InteractionListener(AbsHook): # If the value is still none, we have an issue! if value is None: - print("Couldn't find an appropriate value for interaction {}".format(event.interaction)) + logging.error("Couldn't find an appropriate value for interaction {}".format(event.interaction)) return None # Call the callback diff --git a/main.py b/main.py index d1b0cc5..7d5a901 100644 --- a/main.py +++ b/main.py @@ -3,11 +3,16 @@ import textwrap from typing import Match import hooks +import settings from plugins import identifier, job_commands, management_commands, periodicals, scroll_util, slavestothemachine import client import slack_util +import logging + +logging.basicConfig(filename="run.log", filemode="w", level=logging.DEBUG, format='%(asctime)s - %(levelname)s - %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p') + def main() -> None: wrap = client.get_slack() @@ -52,7 +57,7 @@ def main() -> None: wrap.add_passive(periodicals.RemindJobs()) event_loop = asyncio.get_event_loop() - event_loop.set_debug(slack_util.DEBUG_MODE) + event_loop.set_debug(settings.USE_ASYNC_DEBUG_MODE) event_handling = wrap.handle_events() passive_handling = wrap.run_passives() both = asyncio.gather(event_handling, passive_handling) diff --git a/plugins/job_commands.py b/plugins/job_commands.py index c122546..54fd0a6 100644 --- a/plugins/job_commands.py +++ b/plugins/job_commands.py @@ -1,3 +1,4 @@ +import logging from dataclasses import dataclass from typing import List, Match, Callable, TypeVar, Optional, Iterable, Any, Coroutine @@ -25,7 +26,7 @@ async def alert_user(brother: scroll_util.Brother, saywhat: str) -> None: # Warn if we never find if not succ: - print("Warning: unable to find dm for brother {}".format(brother)) + logging.warning("Unable to find dm conversation for brother {}".format(brother)) # Generic type diff --git a/plugins/periodicals.py b/plugins/periodicals.py index a8027d6..527659b 100644 --- a/plugins/periodicals.py +++ b/plugins/periodicals.py @@ -1,4 +1,5 @@ import asyncio +import logging from datetime import datetime from typing import Optional, List @@ -102,7 +103,7 @@ class RemindJobs(hooks.Passive, JobNotifier): assigns: List[house_management.JobAssignment] = [a for a in assigns if self.is_job_valid(a)] # Now, we want to nag each person. If we don't actually know who they are, so be it. - print("Reminding people who haven't yet done their jobs.") + logging.info("Scheduled reminding people who haven't yet done their jobs.") for a in assigns: # Get the relevant slack ids assignee_ids = await identifier.lookup_brother_userids(a.assignee) @@ -116,7 +117,7 @@ class RemindJobs(hooks.Passive, JobNotifier): # Warn on failure if not success: - print("Tried to nag {} but couldn't find their slack id".format(a.assignee.name)) + logging.warning("Tried to nag {} but couldn't find their slack id".format(a.assignee.name)) # Take a break to ensure no double-shots await asyncio.sleep(10) @@ -204,7 +205,7 @@ class TestPassive(hooks.Passive): client.get_slack().add_hook(listener) # Iterate editing the message every n seconds, for quite some time - for i in range(120): + for i in range(10): make_interactive_msg() await asyncio.sleep(post_interval) diff --git a/settings.py b/settings.py new file mode 100644 index 0000000..0ea4e75 --- /dev/null +++ b/settings.py @@ -0,0 +1,11 @@ +# Use if we want to await tasks one by one +# Hint: We usually don't +SINGLE_THREAD_TASKS = False + + +# If we were interested in performance, this should probably be turned off. However, it's fairly harmless and +# for the most part pretty beneficial to us. +# See https://docs.python.org/3/library/asyncio-dev.html#asyncio-debug-mode +# Note that this occasionally will give us warnings if SINGLE_THREAD_TAKS is False (which it usually is) +# howver, these warnings are harmless, as regardless of if aa task is awaited it still does its job +USE_ASYNC_DEBUG_MODE = False diff --git a/slack_util.py b/slack_util.py index 2e4acbe..971b488 100644 --- a/slack_util.py +++ b/slack_util.py @@ -1,7 +1,8 @@ from __future__ import annotations +import logging from dataclasses import dataclass -from pprint import pprint +from pprint import pformat from time import sleep from typing import Optional, Generator, Callable, Union, Awaitable from typing import TypeVar @@ -9,11 +10,8 @@ from typing import TypeVar from slackclient import SlackClient from slackclient.client import SlackNotConnected -# Enable to do single-threaded and have better exceptions -import plugins import client - -DEBUG_MODE = False +import plugins """ Objects to represent things within a slack workspace @@ -152,26 +150,24 @@ def message_stream(slack: SlackClient) -> Generator[Event, None, None]: while True: try: if slack.rtm_connect(with_team_state=False, auto_reconnect=True): - print("Waiting for messages") + logging.info("Waiting for messages") while True: sleep(0.1) update_list = slack.rtm_read() # Handle each for update in update_list: - print("\nRTM Message received:") - pprint(update) + logging.info("RTM Message received") + logging.debug(pformat(update)) yield message_dict_to_event(update) except (SlackNotConnected, OSError) as e: - print("Error while reading messages:") - print(e) + logging.exception("Error while reading messages.") except (ValueError, TypeError) as e: - print("Malformed message... Restarting connection") - print(e) + logging.exception("Malformed message... Restarting connection") sleep(5) - print("Connection failed - retrying") + logging.warning("Connection failed - retrying") def message_dict_to_event(update: dict) -> Event: