Feat: Add logging to tell when refresh happens.

I think that the git error is just happening from timing out. Trying to fix by
refreshing the connection when it happens.

.vscode/launch.json

@@ -9,7 +9,10 @@
             "type": "debugpy",
             "request": "launch",
             "module": "dakiny_bot",
-            "justMyCode": true
+            "justMyCode": true,
+            "env": {
+                "DEBUG": "true"
+            }
         }
     ]
 }

dakiny_bot/app.py

@@ -1,6 +1,5 @@
 """Main file for bot."""
 
-import logging
 import os
 
 import nextcord
@@ -16,12 +15,6 @@ from .DakinySettings import settings
 
 birthday_list: list[int] = []
 
-logger = logging.getLogger("nextcord")
-logger.setLevel(logging.DEBUG)
-handler = logging.FileHandler(filename="nextcord.log", encoding="utf-8", mode="w")
-handler.setFormatter(logging.Formatter("%(asctime)s:%(levelname)s:%(name)s: %(message)s"))
-logger.addHandler(handler)
-
 
 def run() -> None:
     """Builds and runs bot."""

dakiny_bot/classes/election.py

@@ -5,9 +5,6 @@ from datetime import UTC, datetime, timedelta
 from pathlib import Path
 
 import nextcord
-from sqlalchemy import select, true, update
-from sqlalchemy.orm import Session
-
 from dakiny_bot.classes.nominate_highcouncil_views import NominateHighCouncilView
 from dakiny_bot.classes.nominate_views import NominateView
 from dakiny_bot.classes.voting_highcouncil_views import VoteHighcouncilView
@@ -19,6 +16,7 @@ from dakiny_bot.database.sql_data_classes import (
     Votes,
     engine,
 )
+from dakiny_bot.logger import dakiny_logger
 from dakiny_bot.utils import (
     TEMPLATES_DIR,
     VoteType,
@@ -28,6 +26,8 @@ from dakiny_bot.utils import (
     get_datetime,
     get_election_name,
 )
+from sqlalchemy import select, true, update
+from sqlalchemy.orm import Session
 
 REQUIRED_VOTES_TO_BE_ELECTED = 3
 
@@ -144,20 +144,29 @@ class Election:
     async def check_date(self) -> None:
         """Function checks current date to see if something needs to be run."""
         today = datetime.now(tz=UTC)
+        dakiny_logger.debug("Checking date.")
 
         # check all dates if action is needed
         if today.date() == self.election_start.date():
+            dakiny_logger.debug("Election start.")
             await self.election_start_action()
         elif today.date() == self.voting_start.date():
+            dakiny_logger.debug("Voting start.")
             await self.voting_start_action()
         elif (self.voting_end - timedelta(3)).date() <= today.date() < self.voting_end.date():
+            dakiny_logger.debug("Election reminder.")
             await self.election_reminder()
         elif today.date() == self.voting_end.date():
+            dakiny_logger.debug("Voting end.")
             await self.voting_end_action()
         elif today.date() == self.highcouncil_election_start.date():
+            dakiny_logger.debug("Highcouncil election start.")
             await self.highcouncil_election_start_action()
         elif today.date() == self.term_start.date():
+            dakiny_logger.debug("Term start")
             await self.term_start_action()
+        else:
+            dakiny_logger.warning("Check date didn't do anything. This should never happen.")
 
     async def election_start_action(self) -> None:
         """Performs required actions for when the election cycle starts."""

dakiny_bot/cogs/clan_messages/__init__.py

@@ -6,10 +6,12 @@ from typing import TYPE_CHECKING
 import uvicorn
 from fastapi import FastAPI
 from git import Repo
+from git.exc import GitCommandError
 from nextcord.ext import commands
 
 from dakiny_bot.classes.gitea_webhook import GiteaWebhook
 from dakiny_bot.DakinySettings import settings
+from dakiny_bot.logger import dakiny_logger
 from dakiny_bot.utils import REPO_DIR, edit_clan_council_info, update_clan_messages
 
 if TYPE_CHECKING:
@@ -55,7 +57,12 @@ class ClanMessages(commands.Cog, name="Clan Messages"):
         template_updates = {file.split("/")[1] for file in modified_files if "message_templates" in file}
         channel_updates = {file.split("/")[1] for file in modified_files if file.split("/")[1] not in template_updates}
 
+        try:
             self.origin.pull()
+        except GitCommandError:
+            # I think the git connection timed out. Get a new one.
+            dakiny_logger.info("Refreshing git connection.")
+            self.repo_setup()
         guild: nextcord.Guild = self.bot.get_guild(settings.params.guild_id)
 
         await update_clan_messages(guild, channel_updates)

dakiny_bot/cogs/commands/test.py

@@ -4,6 +4,7 @@ import nextcord
 from nextcord.ext import application_checks, commands
 
 from dakiny_bot.classes.election import Election
+from dakiny_bot.cogs.loops import daily_loop
 from dakiny_bot.DakinySettings import settings
 from dakiny_bot.utils import GUILDS, get_active_election_cycle, get_quarter_name
 
@@ -119,11 +120,8 @@ class TestCog(commands.Cog, name="Test commands."):
         Args:
             interaction (nextcord.Interaction): Interaction with the message.
         """
-        cycle = Election(
-            get_active_election_cycle(),
-            self.bot.get_guild(settings.params.guild_id),
-        )
-        await cycle.check_date()
+        dl = daily_loop.DailyLoop(self.bot)
+        await dl.daily_loop()
         await interaction.send("Test command sent.", ephemeral=True)
 
     @test.subcommand()

dakiny_bot/cogs/loops/daily_loop.py

@@ -13,6 +13,7 @@ from dakiny_bot.app import birthday_list
 from dakiny_bot.classes.election import Election
 from dakiny_bot.DakinySettings import settings
 from dakiny_bot.database.sql_data_classes import UserBirthday, engine
+from dakiny_bot.logger import dakiny_logger
 from dakiny_bot.utils import get_active_election_cycle
 
 if TYPE_CHECKING:
@@ -43,8 +44,10 @@ class DailyLoop(commands.Cog, name="Daily Loop"):
         an active election, runs the check_date() function for the election to perform actions. Finally checks if the
         election is over to delete the current election object.
         """
+        dakiny_logger.debug("Daily loop. Current election: %s.", self.current_election)
         if self.current_election is None:
             self.current_election = self.get_election()
+            dakiny_logger.debug("Current election: %s.", self.current_election)
 
         if self.current_election is not None:
             await self.current_election.check_date()
@@ -78,13 +81,17 @@ class DailyLoop(commands.Cog, name="Daily Loop"):
             Election: Current election cycle, None if there is no election happening.
         """
         cycle = get_active_election_cycle()
+        dakiny_logger.debug("Current cycle: %s.", cycle)
 
         # prevent exception from using cycle as an Int in an array
         if cycle is None:
+            dakiny_logger.info("Cycle was None. Returning without an election.")
             return None
 
         election = Election(cycle, self.bot.get_guild(settings.params.guild_id))
 
+        dakiny_logger.debug("Election active: %s", election.active)
+
         return election if election.active else None
 
     def update_birthdays(self) -> None:

dakiny_bot/logger.py

@@ -0,0 +1,13 @@
+"""Creates logger for Dakiny bot."""
+
+import logging
+import os
+import sys
+
+dakiny_logger = logging.getLogger("default")
+dakiny_logger.setLevel(logging.DEBUG if os.getenv("DEBUG") == "true" else logging.INFO)
+handler = logging.StreamHandler(sys.stdout)
+handler.setFormatter(
+    logging.Formatter("%(asctime)s:%(levelname)s [%(filename)s:%(lineno)s - %(funcName)20s() ] %(message)s")
+)
+dakiny_logger.addHandler(handler)

dakiny_bot/utils.py

@@ -20,6 +20,7 @@ from dakiny_bot.database.sql_data_classes import (
     Votes,
     engine,
 )
+from dakiny_bot.logger import dakiny_logger
 
 from .DakinySettings import settings
 
@@ -34,20 +35,20 @@ VoteType = StrEnum("VoteType", ["COUNCIL", "DISCORDMANAGER", "CLANLEADER"])
 PointType = StrEnum("PointType", ["CLAN", "EVENT"])
 
 
-def get_datetime(day: str) -> datetime:
+def get_datetime(month_day: str) -> datetime:
     """
     Takes in a string month and day and returns a datetime object of that Month/Day this year.
 
     Args:
-        day (str): Month/Day in that format.
+        month_day (str): Month/Day in that format.
 
     Returns:
         datetime: Datetime representation of Month/Day.
     """
     today = datetime.now(tz=UTC).date()
     year = today.year
-    month = int(day.split("/")[0])
-    day = int(day.split("/")[1])
+    month = int(month_day.split("/")[0])
+    day = int(month_day.split("/")[1])
 
     # ensure that year rolls over if current month is December and the next month is less than 12.
     if today.month == calendar.DECEMBER and month < calendar.OCTOBER:
@@ -55,8 +56,10 @@ def get_datetime(day: str) -> datetime:
 
     if today.month == calendar.JANUARY and month > calendar.MARCH:
         year -= 1
-
+    try:
         return datetime(year, month, day, tzinfo=UTC)
+    except ValueError:
+        dakiny_logger.warning("Invalid month day: %s.", month_day)
 
 
 def get_election_name() -> str:
@@ -92,12 +95,14 @@ def get_active_election_cycle() -> int:
         int: cycle index for active election. None for no active cycle
     """
     today = datetime.now(tz=UTC)
+    dakiny_logger.debug("Today is %s", today)
 
     for cycle, election in enumerate(settings.election_cycles):
         if (
             today.date() >= get_datetime(election.election_start).date()
             and today.date() <= get_datetime(election.term_start).date()
         ):
+            dakiny_logger.debug("Cycle is %d", cycle)
             return cycle
 
     # It isn't a current election, get the quarter
@@ -114,13 +119,16 @@ def get_quarter_cycle() -> int:
         int: cycle index for current cycle.
     """
     today = datetime.now(tz=UTC)
+    dakiny_logger.debug("Today is %s", today)
     for cycle, election in enumerate(settings.election_cycles):
         if (
             today.date() >= get_datetime(election.term_start).date()
             and today.date() <= get_datetime(election.term_end).date()
         ):
+            dakiny_logger.debug("Cycle is %d", cycle)
             return cycle
 
+    dakiny_logger.debug("Quarter cycle is None.")
     return None