From 3fb6676fbed368e063ae672acf5d9674dc8efb6a Mon Sep 17 00:00:00 2001 From: Mike Lang Date: Thu, 3 Oct 2024 02:52:45 +1000 Subject: [PATCH] pubbot: Add more detail to logging Wrap raw pubnub messages in a metadata object containing: - time - our hostname - our pid - any inferred information Plus make a message-less log write on startup so we know where there might be gaps. Also do more error handling so that we don't completely lose messages on error. --- zulip_bots/zulip_bots/pubbot.py | 113 +++++++++++++++++++++----------- 1 file changed, 76 insertions(+), 37 deletions(-) diff --git a/zulip_bots/zulip_bots/pubbot.py b/zulip_bots/zulip_bots/pubbot.py index 6a1a696..cdec948 100644 --- a/zulip_bots/zulip_bots/pubbot.py +++ b/zulip_bots/zulip_bots/pubbot.py @@ -1,6 +1,8 @@ import json import logging +import os +import socket import time from .config import get_config @@ -49,7 +51,7 @@ def get_giveaway(): return g -def main(conf_file, message_log_file): +def main(conf_file, message_log_file, name=socket.gethostname()): """Config: zulip_url zulip_email @@ -59,47 +61,84 @@ def main(conf_file, message_log_file): config = get_config(conf_file) client = Client(config["zulip_url"], config["zulip_email"], config["zulip_api_key"]) + message_log = open(message_log_file, "a") + def write_log(log): + message_log.write(json.dumps(log) + '\n') + + write_log({ + "type": "startup", + "host": name, + "pid": os.getpid(), + "time": time.time(), + }) prizes = {} total = None for msg in stream(): - message_log.write(json.dumps(msg) + '\n') - - if msg["c"] == "db_total": - increase = None if total is None else msg["d"] - total - increase_str = "" if increase is None else " (+${:.2f})".format(msg["d"] - total) - giveaway = get_giveaway() - entries_str = "" - if increase is not None and giveaway is not None: - amount = giveaway["amount"] - if (increase + 0.005) % amount < 0.01: - entries = int((increase + 0.005) / amount) - entries_str = " ({} entries of ${:.2f})".format(entries, amount) - logging.info("New donation total: {}{}{}".format(msg["d"], increase_str, entries_str)) - client.send_to_stream("bot-spam", "Donation Firehose", "Donation total is now ${:.2f}{}{}".format(msg["d"], increase_str, entries_str)) - if increase is not None and increase >= 500: - client.send_to_stream("bot-spam", "Notable Donations", "Large donation of ${:.2f} (total ${:.2f}){}".format(increase, msg['d'], entries_str)) - total = msg["d"] - - elif msg["c"] == "db_vue" and msg["d"].get("channel").startswith("prize:"): - d = msg["d"] - prize_id = msg["d"]["channel"].split(":")[1] - data = d["data"] - logging.info(f"Prize update for {prize_id}: {data}") - if prize_id not in prizes: - prizes[prize_id] = get_prize(prize_id) - if "bidder" in data and "bid" in data: - client.send_to_stream("bot-spam", "Bids", "At , {bidder} bid ${bid:.2f} for [{title}](https://desertbus.org/prize/{prize_id})".format( - time = float(msg["p"]["t"]) / 10000000, - bidder = data["bidder"], - bid = data["bid"], - title = prizes[prize_id]["title"], - prize_id = prize_id, - )) - - else: - logging.warning("Unknown message: {}".format(msg)) + log = { + "type": "unknown", + "host": name, + "pid": os.getpid(), + "time": time.time(), + "message": msg, + } + + try: + try: + message_time = float(msg["p"]["t"]) / 10000000 + except (KeyError, ValueError): + message_time = None + + log["message_time"] = message_time + + if msg["c"] == "db_total": + log["type"] == "total" + increase = None if total is None else msg["d"] - total + log["increase"] = increase + increase_str = "" if increase is None else " (+${:.2f})".format(msg["d"] - total) + giveaway = get_giveaway() + entries_str = "" + if increase is not None and giveaway is not None: + amount = giveaway["amount"] + if (increase + 0.005) % amount < 0.01: + entries = int((increase + 0.005) / amount) + log["giveaway_amount"] = amount + log["giveaway_entries"] = entries + entries_str = " ({} entries of ${:.2f})".format(entries, amount) + logging.info("New donation total: {}{}{}".format(msg["d"], increase_str, entries_str)) + client.send_to_stream("bot-spam", "Donation Firehose", "Donation total is now ${:.2f}{}{}".format(msg["d"], increase_str, entries_str)) + if increase is not None and increase >= 500: + client.send_to_stream("bot-spam", "Notable Donations", "Large donation of ${:.2f} (total ${:.2f}){}".format(increase, msg['d'], entries_str)) + total = msg["d"] + + elif msg["c"] == "db_vue" and msg["d"].get("channel").startswith("prize:"): + log["type"] = "prize" + d = msg["d"] + prize_id = msg["d"]["channel"].split(":")[1] + data = d["data"] + logging.info(f"Prize update for {prize_id}: {data}") + if prize_id not in prizes: + prizes[prize_id] = get_prize(prize_id) + log["prize_id"] = prize_id + if "bidder" in data and "bid" in data: + log["bidder"] = data["bidder"] + log["bid"] = data["bid"] + client.send_to_stream("bot-spam", "Bids", "At , {bidder} bid ${bid:.2f} for [{title}](https://desertbus.org/prize/{prize_id})".format( + time = message_time, + bidder = data["bidder"], + bid = data["bid"], + title = prizes[prize_id]["title"], + prize_id = prize_id, + )) + + else: + logging.warning("Unknown message: {}".format(msg)) + except Exception: + logging.exception(f"Failed to handle message {msg}") + log["type"] = "error" + + write_log(log) if __name__ == '__main__':