From 0db75c689d1c0756a37dd150924f9a07576ea09f Mon Sep 17 00:00:00 2001 From: Addison Gourluck Date: Wed, 16 Nov 2022 08:42:19 +1000 Subject: [PATCH] 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. --- slackbot.py | 31 ++++++++-------- timtamcam.py | 92 ++++++++++++++++++++++++++++------------------- timtamcam.service | 2 +- 3 files changed, 71 insertions(+), 54 deletions(-) diff --git a/slackbot.py b/slackbot.py index f2693fe..357d99f 100644 --- 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 index e8c7478..da6c269 100755 --- 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,7 +29,6 @@ # in grams DELTA_WEIGHT = 5 -logger = logging.getLogger(__name__) class TimTamCam(SlackBot): """ @@ -37,13 +36,14 @@ class TimTamCam(SlackBot): """ 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,17 +52,24 @@ 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"] @@ -70,16 +77,18 @@ def load_camera_url(self): 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,11 +196,16 @@ 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 @@ -194,17 +213,17 @@ def monitor_weight(self): 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 index 5b9a7e0..e7fc3a2 100644 --- 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