From fc834d19237ea95a36b650d2beb3935e2dea5af7 Mon Sep 17 00:00:00 2001
From: dnns01 <mail@dnns01.de>
Date: Wed, 16 Dec 2020 22:51:50 +0100
Subject: [PATCH] Added debug messages to figure out, why the hell the loops
 are not working as expected!

---
 hausgeist.py |  8 ++++++--
 info_cog.py  | 17 ++++++++++++-----
 pipi_cog.py  | 19 +++++++++++++------
 3 files changed, 31 insertions(+), 13 deletions(-)

diff --git a/hausgeist.py b/hausgeist.py
index f8b2705..16d6d01 100644
--- a/hausgeist.py
+++ b/hausgeist.py
@@ -1,3 +1,5 @@
+import asyncio
+import logging
 import os
 from abc import ABC
 
@@ -10,6 +12,8 @@ from info_cog import InfoCog
 from pipi_cog import PipiCog
 from vote_cog import VoteCog
 
+logging.basicConfig(level=logging.INFO, filename='hausgeist.log')
+
 load_dotenv()
 IRC_TOKEN = os.getenv("IRC_TOKEN")
 CLIENT_ID = os.getenv("CLIENT_ID")
@@ -51,8 +55,8 @@ class HaugeBot(commands.Bot, ABC):
 
     async def event_ready(self):
         print('Logged in')
-        await self.pipi_cog.start_pipimeter_loop()
-        await self.info_cog.start_info_loop()
+        asyncio.create_task(self.info_cog.info_loop())
+        asyncio.create_task(self.pipi_cog.pipimeter_loop())
 
     @staticmethod
     def get_percentage(part, total):
diff --git a/info_cog.py b/info_cog.py
index cac457f..51e6d89 100644
--- a/info_cog.py
+++ b/info_cog.py
@@ -1,7 +1,9 @@
 import asyncio
 import json
+import logging
 import os
 import random
+from datetime import datetime
 
 from twitchio.ext import commands
 
@@ -11,7 +13,7 @@ class InfoCog:
     def __init__(self, bot):
         self.bot = bot
         self.info_file = os.getenv("INFO_JSON")
-        self.INFO_LOOP = int(os.getenv("INFO_LOOP"))
+        self.INFO_LOOP = float(os.getenv("INFO_LOOP"))
         self.INFO_COLOR = os.getenv("INFO_COLOR")
         self.info = []
         self.load_info()
@@ -21,19 +23,24 @@ class InfoCog:
 
         info_file = open(self.info_file, mode='r')
         self.info = json.load(info_file)
-        pass
-
-    async def start_info_loop(self):
-        asyncio.create_task(self.info_loop())
 
     async def info_loop(self):
         """ Send !pipimeter into the chat every x Minutes. Also check, whether the stream was offline for x Minutes.
          If this is true, reset the pipi counter, as you can assume, that the stream recently started."""
 
+        logging.log(logging.INFO, f"Info loop started. {datetime.now()} {self}")
+
         while True:
+            logging.log(logging.INFO, f"Inside Info loop. Sleep for {self.INFO_LOOP} minutes. {datetime.now()} {self}")
             await asyncio.sleep(self.INFO_LOOP * 60)
+            logging.log(logging.INFO, f"Inside Info loop finished sleeping now. {datetime.now()} {self}")
 
             if await self.bot.stream():
+                logging.log(logging.INFO,
+                            f"Inside Info loop. Stream is online, so send a message now!!! {datetime.now()} {self}")
                 channel = self.bot.channel()
                 message = f"Psssst... wusstest du eigentlich schon, {random.choice(self.info)}"
                 await self.bot.send_me(channel, message, self.INFO_COLOR)
+
+            logging.log(logging.INFO,
+                        f"Inside Info loop. Ooooookay, Loop ended, let's continue with the next round!!! {datetime.now()} {self}")
diff --git a/pipi_cog.py b/pipi_cog.py
index f3c84cb..a79bd77 100644
--- a/pipi_cog.py
+++ b/pipi_cog.py
@@ -1,5 +1,7 @@
 import asyncio
+import logging
 import os
+from datetime import datetime
 
 from twitchio.dataclasses import Message
 from twitchio.ext import commands
@@ -21,12 +23,6 @@ class PipiCog:
         self.pipi_task = None
         self.pipi_votes = {}
 
-    async def start_pipimeter_loop(self):
-        # Wait for one minute to avoid this loop and the info loop to post directly after each other
-        await asyncio.sleep(60)
-
-        asyncio.create_task(self.pipimeter_loop())
-
     async def notify_pipi(self, ctx, use_timer=True, message=None):
         """ Write a message in chat, if there hasn't been a notification since DELAY seconds. """
 
@@ -73,12 +69,20 @@ class PipiCog:
         """ Send !pipimeter into the chat every x Minutes. Also check, whether the stream was offline for x Minutes.
          If this is true, reset the pipi counter, as you can assume, that the stream recently started."""
 
+        logging.log(logging.INFO,
+                    f"Pipi loop started To have an offset from Info loop, wait for one minute. {datetime.now()} {self}")
         offline_since = 0
+        await asyncio.sleep(60)
 
         while True:
+            logging.log(logging.INFO,
+                        f"Inside Pipi loop. Sleep for {self.PIPIMETER_LOOP} minutes. {datetime.now()} {self}")
             await asyncio.sleep(self.PIPIMETER_LOOP * 60)
+            logging.log(logging.INFO, f"Inside Pipi loop finished sleeping now. {datetime.now()} {self}")
 
             if await self.bot.stream():
+                logging.log(logging.INFO,
+                            f"Inside Pipi loop. Stream is online, so check for threshold!!! {datetime.now()} {self}")
                 if offline_since >= self.RESET_THRESHOLD:
                     self.pipi_votes = {}
                 offline_since = 0
@@ -90,6 +94,9 @@ class PipiCog:
             else:
                 offline_since += self.PIPIMETER_LOOP
 
+            logging.log(logging.INFO,
+                        f"Inside Pipi loop. Ooooookay, Loop ended, let's continue with the next round!!! {datetime.now()} {self}")
+
     @commands.command(name="pipi", aliases=["Pipi"])
     async def cmd_pipi(self, ctx):
         """ User mentioned there is a need to go to toilet. """
-- 
GitLab