Improved logging

.gitignore

@@ -7,6 +7,7 @@ sheets_token.json
 *.dir
 *.pyc
 *.swp
+*.log
 script_log.txt
 towels_rolled
 user_scrolls

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:")
+                logging.info("\nInteraction Event received:")
-                pprint(payload)
+                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
 

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

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)

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

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)
 

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

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
-
+import plugins
-DEBUG_MODE = False
 
 """
 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:")
+                        logging.info("RTM Message received")
-                        pprint(update)
+                        logging.debug(pformat(update))
                         yield message_dict_to_event(update)
 
         except (SlackNotConnected, OSError) as e:
-            print("Error while reading messages:")
+            logging.exception("Error while reading messages.")
-            print(e)
         except (ValueError, TypeError) as e:
-            print("Malformed message... Restarting connection")
+            logging.exception("Malformed message... Restarting connection")
-            print(e)
 
         sleep(5)
-        print("Connection failed - retrying")
+        logging.warning("Connection failed - retrying")
 
 
 def message_dict_to_event(update: dict) -> Event: