Improvements to logging, dynamic borders, no midnight spamming

Put the logger on the object, so we get the subclass logging too. More detailed logging. Make Halloween/Christmas masks automatic in October/December. Stop logging messages in the middle of the night. Make message to have no decimal place in Slack message. Made the service restart after failure every 5 minutes, not every 10 seconds.
AddisonG · Nov 15, 2022 · 0db75c6 · 0db75c6
1 parent a0e5fe5
commit 0db75c6
Show file tree

Hide file tree

Showing 3 changed files with 71 additions and 54 deletions.
diff --git a/slackbot.py b/slackbot.py
@@ -8,11 +8,6 @@
 from slack.errors import SlackApiError
 
 
-LOGFILE_FORMAT = '%(asctime)-15s %(module)s %(levelname)s: %(message)s'
-logger = logging.getLogger(__name__)
-logging.basicConfig(filename='timtamcam.log', level=logging.INFO, format=LOGFILE_FORMAT)
-
-
 class SlackBot():
     """
     Generic Slackbot implementation that allows sending messages to users,
@@ -21,7 +16,11 @@ class SlackBot():
     Based off Lachlan Archibald's excellent implementation from ogdevicebot.
     """
 
-    def __init__(self, token: str):
+    def __init__(self, name: str, token: str):
+        if not self.logger:
+            self.logger = logging.getLogger(__name__)
+            LOGFILE_FORMAT = '%(asctime)-15s %(module)s %(levelname)s: %(message)s'
+            logging.basicConfig(filename=f"{name}.log", level=logging.INFO, format=LOGFILE_FORMAT)
         if not token or not token.startswith("xoxb"):
             raise RuntimeError("Valid bot token needed - must start with 'xoxb'")
         # Uploading a file can take between 20 and 35 seconds.
@@ -62,7 +61,7 @@ def send_message(self, recipient: Union[str, dict], message: str):
         Send a message to a given Slack user or channel
         """
         if not recipient:
-            logger.error("Recipient data not provided")
+            self.logger.error("Recipient data not provided")
             return
 
         if type(recipient) is dict:
@@ -72,40 +71,40 @@ def send_message(self, recipient: Union[str, dict], message: str):
             r_name = "???"
             r_id = recipient
 
-        logger.info(f"Sending message to '{r_name}' ({r_id}): \"{message}\"")
+        self.logger.info(f"Sending message to '{r_name}' ({r_id}): \"{message}\"")
         response = self.client.chat_postMessage(channel=r_id, text=message)
         if not response['ok']:
-            logger.info(f"Failed to send message to '{r_name}' ({r_id}): \"{message}\"")
+            self.logger.info(f"Failed to send message to '{r_name}' ({r_id}): \"{message}\"")
 
     def delete_messages(self):
         """
         Delete all direct messages (only) sent by this bot
         """
-        logger.info("Deleting direct messages sent by bot")
+        self.logger.info("Deleting direct messages sent by bot")
 
         @backoff.on_exception(backoff.expo, SlackApiError, max_time=60)
         def delete_message(message, conversation):
             try:
-                logger.debug(f"Message: <{message['text']}>")
-                logger.debug(f"Deleting message <{message['ts']}> from conversation <{conversation['id']}>")
+                self.logger.debug(f"Message: <{message['text']}>")
+                self.logger.debug(f"Deleting message <{message['ts']}> from conversation <{conversation['id']}>")
                 self.client.chat_delete(channel=conversation['id'], ts=message['ts'])['ok']
             except SlackApiError as api_error:
                 # if we encounter ratelimiting, raise the exception to backoff
                 if api_error.response["error"] == "ratelimited":
                     raise
                 # if it's anything else, log and continue.
-                logger.error(api_error)
+                self.logger.error(api_error)
 
         try:
             # get all conversations (single person direct messages only) from this bot
             conversations = self.client.conversations_list(types="im")['channels']
-            logger.debug("Retrieved <%d> conversations", len(conversations))
+            self.logger.debug("Retrieved <%d> conversations", len(conversations))
             for conversation in conversations:
                 # for each conversation, delete all messages
                 messages = self.client.conversations_history(channel=conversation['id'])['messages']
-                logger.debug("Retrieved <%d> messages in conversation <%s>",
+                self.logger.debug("Retrieved <%d> messages in conversation <%s>",
                             len(messages), conversation['id'])
                 for message in messages:
                     delete_message(message, conversation)
         except SlackApiError as api_error:
-            logger.error(api_error)
+            self.logger.error(api_error)
diff --git a/timtamcam.py b/timtamcam.py
@@ -4,11 +4,11 @@
 import sys
 import cv2
 import json
-import time
 import logging
 import requests
 import argparse
 import imageio
+from datetime import datetime
 
 from slack.errors import SlackApiError
 
@@ -29,21 +29,21 @@
 # in grams
 DELTA_WEIGHT = 5
 
-logger = logging.getLogger(__name__)
 
 class TimTamCam(SlackBot):
     """
     Watches the Tim Tams. Ever vigilant.
     """
 
     def __init__(self, debug=False):
+        self.logger = logging.getLogger(__name__)
         if debug:
             self.setup_logging(logging.DEBUG)
         else:
             self.setup_logging(logging.INFO)
-        logger.info("Tim Tam Bot starting!")
+        self.logger.info("Tim Tam Bot starting!")
 
-        super().__init__(bot_token)
+        super().__init__(name="tim-tam-cam", token=bot_token)
 
         # The script directory (where this file, config, etc, is stored)
         self.script_dir = os.path.dirname(os.path.realpath(__file__))
@@ -52,34 +52,43 @@ def __init__(self, debug=False):
         self.load_camera_url()
 
         # Make sure we're in the bots channel
-        logger.info("Joining the bots channel")
+        self.logger.info("Joining the bots channel")
         self.bot_channel = json.load(open(f"{self.script_dir}/bot_channel.json"))
         self.join_channel_by_id(self.bot_channel["id"])
 
         self.mask = None
+        self.border = None
+
         # The mask is SUBTRACTED, then the border is then ADDED
-        #self.mask = cv2.imread(f"{self.script_dir}/christmas-mask.png", cv2.IMREAD_COLOR)
-        #self.border = cv2.imread(f"{self.script_dir}/christmas-border.png", cv2.IMREAD_COLOR)
+        if datetime.now().month == 12:
+            self.mask = cv2.imread(f"{self.script_dir}/christmas-mask.png", cv2.IMREAD_COLOR)
+            self.border = cv2.imread(f"{self.script_dir}/christmas-border.png", cv2.IMREAD_COLOR)
+        elif datetime.now().month == 10:
+            self.mask = cv2.imread(f"{self.script_dir}/halloween-mask.png", cv2.IMREAD_COLOR)
+            self.border = cv2.imread(f"{self.script_dir}/halloween-border.png", cv2.IMREAD_COLOR)
+
 
     def load_camera_url(self):
-        logger.info("Attempting to find camera IP by MAC address")
+        self.logger.info("Attempting to find camera IP by MAC address")
         with open(f"{self.script_dir}/camera.json") as cam_file:
             cam_details = json.load(cam_file)
             network = cam_details["network"]
             username = cam_details["username"]
             password = cam_details["password"]
             mac = cam_details["mac"]
 
+        # camera_ip = "192.168.252.22"
         camera_ip = find_ip_by_mac(network, mac)
 
         if not camera_ip:
-            raise RuntimeError("Could not find camera URL")
+            raise RuntimeError(f"Could not find camera ({mac}) on {network}.")
 
-        logger.info(f"Found camera '{mac}' at '{camera_ip}'.")
+        self.logger.info(f"Found camera '{mac}' at '{camera_ip}'.")
 
         # stream1 is 1080p, stream2 is 360p
         self.stream_url = f"rtsp://{username}:{password}@{camera_ip}/stream1"
 
+
     def setup_scales(self):
         # GPIO port 5 = DATA and 6 = CLOCK
         self.hx = HX711(5, 6)
@@ -88,53 +97,57 @@ def setup_scales(self):
         self.hx.reset()
         self.hx.tare()
 
+
     def setup_logging(self, level=logging.INFO):
         # Log to a file
         logging.basicConfig(filename='timtamcam.log', format=LOGFILE_FORMAT)
-        logger.setLevel(level)
+        self.logger.setLevel(level)
 
         # Log to stdout
         formatter = logging.Formatter(fmt=STDOUT_FORMAT)
         log_handler_stdout = logging.StreamHandler(sys.stdout)
         log_handler_stdout.setFormatter(formatter)
         log_handler_stdout.setLevel(level)
-        logger.addHandler(log_handler_stdout)
+        self.logger.addHandler(log_handler_stdout)
+
 
     def alert(self, num_timtams: float, previous_weight: float):
         try:
-            self.record_gif(4, 2)
+            self.record_gif(4, 3)
         except Exception as e:
-            logger.error("Failed to record a gif!")
-            logger.error(e)
+            self.logger.error("Failed to record a gif!")
+            self.logger.error(e)
 
             # Try to recover the camera
             try:
                 self.load_camera_url()
-                self.record_gif(4, 2)
-                logger.info("Successfully recovered from bad camera!")
+                self.record_gif(4, 3)
+                self.logger.info("Successfully recovered from bad camera!")
             except Exception:
                 self.send_message(self.bot_channel, "Timtams tampering detected! But the camera is disconnected...")
                 return
 
         if previous_weight <= self.hx.get_weight(15) + DELTA_WEIGHT:
-            logger.info("Weight has not changed, after recording video. Will NOT post to Slack.")
+            self.logger.info("Weight has not changed, after recording video. Will NOT post to Slack.")
             return
 
         try:
-            logger.debug("Uploading file to Slack")
-            self.send_file(self.bot_channel, "/tmp/timtam-thief.gif", f"Timtam tampering detected! Someone took {int(round(num_timtams, 0))} Tim Tams!")
+            self.logger.debug("Uploading file to Slack")
+            self.send_file(self.bot_channel, "/tmp/timtam-thief.gif",
+                f"Timtam tampering detected! Someone took {round(num_timtams)} Tim Tams!")
         except SlackApiError as api_error:
-            logger.error(api_error)
+            self.logger.error(api_error)
         except requests.exceptions.RequestException as e:
             raise SystemExit(e)
 
 
     def record_gif(self, duration, fps):
-        logger.info("Recording a gif of the thief")
+        self.logger.info("Recording a gif of the thief")
         cap = cv2.VideoCapture(self.stream_url)
         stream_fps = int(cap.get(cv2.CAP_PROP_FPS))
         # stream_height = int(cap.get(cv2.CAP_PROP_FRAME_HEIGHT))
         # stream_width = int(cap.get(cv2.CAP_PROP_FRAME_WIDTH))
+        self.logger.debug("Connected to stream URL")
 
         frames = 0
         images = []
@@ -159,21 +172,22 @@ def record_gif(self, duration, fps):
                 images.append(rgb_frame)
 
         # Write frames to gif
-        logger.debug("Saving timtam thief image.")
+        self.logger.debug("Saving timtam thief image.")
         imageio.mimsave('/tmp/timtam-thief.gif', images, duration=0.3)
-        logger.info("Saved gif")
+        self.logger.info("Saved gif")
 
         cap.release()
 
+
     def camera_check(self, cap, ret, frame):
         if not cap.isOpened() or not ret or frame is None or frame.size == 0:
             cap.release()
-            logger.error("Critical camera error")
+            self.logger.error("Critical camera error")
             raise RuntimeError("Camera is unreachable, or had other error.")
 
 
-    def monitor_weight(self):
-        logger.info("Now monitoring Tim Tams")
+    def monitor_loop(self):
+        self.logger.info("Now monitoring Tim Tams")
         timtam_weight = 18.3
 
         item = timtam_weight
@@ -182,29 +196,34 @@ def monitor_weight(self):
         while True:
             try:
                 weight = self.hx.get_weight(15)
-                logger.debug(f"Weight: {weight}")
+                self.logger.debug(f"Weight: {round(weight, 1)}g")
                 if previous is not None:
-                    timtam_change = round((previous - weight) / item, 1)
-                    if timtam_change > 0.8:
-                        # Someone has taken 80% or more of a timtam. Close enough!
+                    hour = datetime.now().hour
+                    if hour >= 19 or hour <= 4:
+                        # Don't record thefts after 7:59pm, or before 4:59am
+                        continue
+
+                    timtam_change = round((previous - weight) / item, 2)
+                    if timtam_change >= 0.85:
+                        # Someone has taken 85% or more of a timtam. Close enough!
                         self.alert(timtam_change, previous)
                         previous = None
                         continue
 
                 previous = weight
 
             except (KeyboardInterrupt, SystemExit) as e:
-                logger.error(str(e))
+                self.logger.error(str(e))
                 RPi.GPIO.cleanup()
                 return
 
+
     # This function is run as part of the daemon
     def run(self):
-        logger.info("Setting up the scales")
+        self.logger.info("Setting up the scales")
         self.setup_scales()
 
-        # Watch (loop)
-        self.monitor_weight()
+        self.monitor_loop()
 
 
 if __name__ == "__main__":
@@ -215,8 +234,7 @@ def run(self):
 
     # parser.add_argument("--mac", "-m", type=str, required=True,
     #     help="The MAC address of the camera.")
-    parser.add_argument("--debug", "-x", action='store_true',
-        help="Enable debugging,")
+    parser.add_argument("--debug", "-x", action='store_true', help="Enable debugging.")
 
     # sys.argv[1:]
     args = parser.parse_args()

diff --git a/timtamcam.service b/timtamcam.service
@@ -8,7 +8,7 @@ Description=Tim Tam Cam
 WorkingDirectory=/home/pi/tim-tam-cam/
 ExecStart=/usr/bin/sudo /usr/bin/env python3 /home/pi/tim-tam-cam/timtamcam.py
 Restart=always
-RestartSec=10
+RestartSec=300
 User=pi
 Group=pi