diff --git a/main.py b/main.py index bfbe81b..06ce9eb 100644 --- a/main.py +++ b/main.py @@ -6,6 +6,7 @@ import alaric from alaric import Cursor from dotenv import load_dotenv +from logoo import PrimaryLogger import suggestions @@ -29,6 +30,9 @@ shard_logger = logging.getLogger("disnake.shard") shard_logger.setLevel(logging.WARNING) +httpx_logger = logging.getLogger("httpx") +httpx_logger.setLevel(logging.WARNING) + suggestions_logger = logging.getLogger("suggestions") suggestions_logger.setLevel(logging.DEBUG) member_stats_logger = logging.getLogger("suggestions.objects.stats.member_stats") @@ -40,6 +44,18 @@ async def run_bot(): log = logging.getLogger(__name__) bot = await suggestions.create_bot() + logger: PrimaryLogger = PrimaryLogger( + __name__, + base_url="https://logs.suggestions.gg", + org="default", + stream="prod_bot" if bot.is_prod else "test_bot", + username=os.environ["LOGOO_USER"], + password=os.environ["LOGOO_PASSWORD"], + poll_time=15, + global_metadata={"cluster": bot.cluster_id}, + ) + await logger.start_consumer() + # Make sure we don't shutdown due to a previous shutdown request cursor: Cursor = ( Cursor.from_document(bot.db.cluster_shutdown_requests) diff --git a/requirements.txt b/requirements.txt index 950813e..ce587aa 100644 --- a/requirements.txt +++ b/requirements.txt @@ -53,3 +53,4 @@ yarl==1.7.2 zonis==1.2.5 types-aiobotocore==2.11.2 aiobotocore==2.11.2 +logoo==1.1.0 \ No newline at end of file diff --git a/suggestions/bot.py b/suggestions/bot.py index ea87a85..6590be3 100644 --- a/suggestions/bot.py +++ b/suggestions/bot.py @@ -18,9 +18,10 @@ from alaric import Cursor from bot_base.wraps import WrappedChannel from cooldowns import CallableOnCooldown -from disnake import Locale, LocalizationKeyError, GatewayParams +from disnake import Locale, LocalizationKeyError from disnake.ext import commands from bot_base import BotBase, BotContext, PrefixNotFound +from logoo import Logger from suggestions import State, Colors, Emojis, ErrorCode, Garven from suggestions.exceptions import ( @@ -48,6 +49,7 @@ from suggestions.zonis_routes import ZonisRoutes log = logging.getLogger(__name__) +logger = Logger(__name__) class SuggestionsBot(commands.AutoShardedInteractionBot, BotBase): @@ -189,7 +191,7 @@ def error_embed( text=f"Error code {error_code.value} | Cluster ID {self.cluster_id}" ) - log.debug("Encountered %s", error_code.name) + logger.debug("Encountered %s", error_code.name) elif error: embed.set_footer(text=f"Error ID {error.id}") @@ -529,6 +531,14 @@ async def on_slash_command_error( elif isinstance(exception, disnake.NotFound): log.debug("disnake.NotFound: %s", exception.text) + logger.debug( + "disnake.NotFound: %s", + exception.text, + extra_metadata={ + "guild_id": interaction.guild_id, + "author_id": interaction.author.id, + }, + ) gid = interaction.guild_id if interaction.guild_id else None await interaction.send( embed=self.error_embed( @@ -544,6 +554,14 @@ async def on_slash_command_error( elif isinstance(exception, disnake.Forbidden): log.debug("disnake.Forbidden: %s", exception.text) + logger.debug( + "disnake.Forbidden: %s", + exception.text, + extra_metadata={ + "guild_id": interaction.guild_id, + "author_id": interaction.author.id, + }, + ) await interaction.send( embed=self.error_embed( exception.text, @@ -573,6 +591,9 @@ async def on_slash_command_error( log.debug( "disnake.HTTPException: Interaction has already been acknowledged" ) + logger.debug( + "disnake.HTTPException: Interaction has already been acknowledged" + ) return ih: InteractionHandler = await InteractionHandler.fetch_handler( @@ -793,7 +814,7 @@ async def process_update_bot_listings(): json=body, ) as r: if r.status != 200: - log.warning("%s", r.text) + logger.warning("%s", r.text) log.debug("Updated bot listings") await self.sleep_with_condition( @@ -939,6 +960,9 @@ async def inner(): await self.sleep_with_condition(60, lambda: self.state.is_closing) except (aiohttp.ClientConnectorError, ConnectionRefusedError): log.warning("push_status failed to connect, retrying in 10 seconds") + logger.warning( + "push_status failed to connect, retrying in 10 seconds" + ) await self.sleep_with_condition(10, lambda: self.state.is_closing) except Exception as e: if not self.is_prod: @@ -950,6 +974,10 @@ async def inner(): "Status update failed: %s", tb, ) + logger.error( + "Status update failed: %s", + tb, + ) await self.garven.notify_devs( title="Status page ping error", description=tb, diff --git a/suggestions/clunk2/edits.py b/suggestions/clunk2/edits.py index 0a35be2..e172b69 100644 --- a/suggestions/clunk2/edits.py +++ b/suggestions/clunk2/edits.py @@ -1,10 +1,10 @@ from __future__ import annotations import asyncio -import logging from typing import TYPE_CHECKING import disnake +from logoo import Logger from suggestions.low_level import MessageEditing from suggestions.objects import Suggestion @@ -12,7 +12,7 @@ if TYPE_CHECKING: from suggestions import SuggestionsBot -log = logging.getLogger(__name__) +logger = Logger(__name__) pending_edits: set[str] = set() @@ -24,17 +24,28 @@ async def update_suggestion_message( time_after: float = 10, ): if suggestion.suggestion_id in pending_edits: - log.debug("Ignoring already existing item %s", suggestion.suggestion_id) + logger.debug( + "Ignoring already existing item %s", + suggestion.suggestion_id, + extra_metadata={ + "guild_id": suggestion.guild_id, + "suggestion_id": suggestion.suggestion_id, + }, + ) return pending_edits.add(suggestion.suggestion_id) await asyncio.sleep(time_after) if suggestion.channel_id is None or suggestion.message_id is None: - log.debug( + logger.debug( "Suggestion %s had a NoneType by the time it was to be edited channel_id=%s, message_id=%s", suggestion.suggestion_id, suggestion.channel_id, suggestion.message_id, + extra_metadata={ + "guild_id": suggestion.guild_id, + "suggestion_id": suggestion.suggestion_id, + }, ) pending_edits.discard(suggestion.suggestion_id) return @@ -50,6 +61,13 @@ async def update_suggestion_message( message_id=up_to_date_suggestion.message_id, ).edit(embed=await up_to_date_suggestion.as_embed(bot)) except (disnake.HTTPException, disnake.NotFound): - log.error("Failed to update suggestion %s", suggestion.suggestion_id) + logger.error( + "Failed to update suggestion %s", + suggestion.suggestion_id, + extra_metadata={ + "guild_id": suggestion.guild_id, + "suggestion_id": suggestion.suggestion_id, + }, + ) pending_edits.discard(suggestion.suggestion_id) diff --git a/suggestions/cogs/blacklist_cog.py b/suggestions/cogs/blacklist_cog.py index 8c7c408..70ef7f6 100644 --- a/suggestions/cogs/blacklist_cog.py +++ b/suggestions/cogs/blacklist_cog.py @@ -1,18 +1,18 @@ from __future__ import annotations -import logging from typing import TYPE_CHECKING import disnake from commons.caching import NonExistentEntry from disnake.ext import commands +from logoo import Logger from suggestions.objects import GuildConfig, Suggestion if TYPE_CHECKING: from suggestions import State, SuggestionsBot -log = logging.getLogger(__name__) +logger = Logger(__name__) class BlacklistCog(commands.Cog): @@ -61,6 +61,16 @@ async def add( "They will be unable to create suggestions in the future.", ephemeral=True, ) + logger.debug( + "User %s added %s to the blocklist for guild %s", + interaction.author.id, + suggestion.suggestion_author_id, + interaction.guild_id, + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + }, + ) @blocklist.sub_command() async def remove( @@ -102,6 +112,16 @@ async def remove( guild_config.blocked_users.discard(user_id) await self.bot.db.guild_configs.upsert(guild_config, guild_config) await interaction.send("I have un-blocklisted that user for you.") + logger.debug( + "User %s removed %s from the blocklist for guild %s", + interaction.author.id, + user_id, + interaction.guild_id, + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + }, + ) @add.autocomplete("suggestion_id") @remove.autocomplete("suggestion_id") @@ -120,9 +140,10 @@ async def get_sid_for( ) else: if not values: - log.debug( + logger.debug( "Values was found, but empty in guild %s thus populating", interaction.guild_id, + extra_metadata={"guild_id": interaction.guild_id}, ) values: list[str] = await self.state.populate_sid_cache( interaction.guild_id diff --git a/suggestions/cogs/guild_config_cog.py b/suggestions/cogs/guild_config_cog.py index 7b90c55..4bc122f 100644 --- a/suggestions/cogs/guild_config_cog.py +++ b/suggestions/cogs/guild_config_cog.py @@ -1,12 +1,12 @@ from __future__ import annotations -import logging from typing import TYPE_CHECKING import cooldowns import disnake from disnake import Guild from disnake.ext import commands +from logoo import Logger from suggestions import Stats from suggestions.cooldown_bucket import InteractionBucket @@ -18,7 +18,7 @@ if TYPE_CHECKING: from suggestions import SuggestionsBot, State -log = logging.getLogger(__name__) +logger = Logger(__name__) class GuildConfigCog(commands.Cog): @@ -55,11 +55,15 @@ async def channel( ).format(channel.mention), ephemeral=True, ) - log.debug( + logger.debug( "User %s changed suggestions channel to %s in guild %s", interaction.author.id, channel.id, interaction.guild_id, + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + }, ) await self.stats.log_stats( interaction.author.id, @@ -86,11 +90,15 @@ async def logs( ), ephemeral=True, ) - log.debug( + logger.debug( "User %s changed logs channel to %s in guild %s", interaction.author.id, channel.id, interaction.guild_id, + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + }, ) await self.stats.log_stats( interaction.author.id, @@ -128,11 +136,15 @@ async def queue_channel( extras={"CHANNEL": channel.mention}, ) ) - log.debug( + logger.debug( "User %s changed physical queue channel to %s in guild %s", interaction.author.id, channel.id, interaction.guild_id, + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + }, ) await self.stats.log_stats( interaction.author.id, @@ -163,11 +175,15 @@ async def queue_log_channel( if channel is not None: msg = msg.format(channel.mention) await ih.send(msg) - log.debug( + logger.debug( "User %s changed rejected queue log channel to %s in guild %s", interaction.author.id, channel.id if channel is not None else None, interaction.guild_id, + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + }, ) await self.stats.log_stats( interaction.author.id, @@ -388,11 +404,15 @@ async def get( raise InvalidGuildConfigOption await interaction.send(embed=embed, ephemeral=True) - log.debug( + logger.debug( "User %s viewed the %s config in guild %s", interaction.author.id, config, interaction.guild_id, + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + }, ) await self.stats.log_stats( interaction.author.id, @@ -546,10 +566,14 @@ async def send_full_config(self, interaction: disnake.GuildCommandInteraction): timestamp=self.bot.state.now, ).set_author(name=guild.name, icon_url=icon_url) await interaction.send(embed=embed, ephemeral=True) - log.debug( + logger.debug( "User %s viewed the global config in guild %s", interaction.author.id, interaction.guild_id, + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + }, ) await self.stats.log_stats( interaction.author.id, @@ -879,9 +903,13 @@ async def modify_guild_config( user_message, ephemeral=True, ) - log.debug( + logger.debug( log_message, interaction.guild_id, + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + }, ) await self.stats.log_stats( interaction.author.id, diff --git a/suggestions/cogs/help_guild_cog.py b/suggestions/cogs/help_guild_cog.py index a65bba6..e2c89a7 100644 --- a/suggestions/cogs/help_guild_cog.py +++ b/suggestions/cogs/help_guild_cog.py @@ -2,7 +2,6 @@ import datetime import io -import logging from typing import TYPE_CHECKING, Optional import disnake @@ -11,6 +10,7 @@ from disnake.ext import commands from disnake.utils import format_dt from humanize import naturaldate +from logoo import Logger from suggestions import ErrorCode from suggestions.objects import Error @@ -18,7 +18,7 @@ if TYPE_CHECKING: from suggestions import SuggestionsBot, State -log = logging.getLogger(__name__) +logger = Logger(__name__) class HelpGuildCog(commands.Cog): diff --git a/suggestions/cogs/suggestion_cog.py b/suggestions/cogs/suggestion_cog.py index d2b38dd..98ab47c 100644 --- a/suggestions/cogs/suggestion_cog.py +++ b/suggestions/cogs/suggestion_cog.py @@ -1,6 +1,5 @@ from __future__ import annotations -import logging from typing import TYPE_CHECKING, Optional import cooldowns @@ -9,6 +8,7 @@ from bot_base.wraps import WrappedChannel from disnake import Guild, ButtonStyle from disnake.ext import commands, components +from logoo import Logger from suggestions import checks, Stats from suggestions.clunk2 import update_suggestion_message @@ -30,7 +30,7 @@ from alaric import Document from suggestions import SuggestionsBot, State -log = logging.getLogger(__name__) +logger = Logger(__name__) class SuggestionsCog(commands.Cog): @@ -82,11 +82,10 @@ async def suggestion_up_vote( ), ephemeral=True, ) - # log.debug( - # "Member %s modified their vote on %s to an up vote", - # member_id, - # suggestion_id, - # ) + logger.debug( + f"Member {member_id} modified their vote on {suggestion_id} to a up vote", + extra_metadata={"suggestion_id": suggestion_id}, + ) else: suggestion.up_voted_by.add(member_id) await self.state.suggestions_db.upsert(suggestion, suggestion) @@ -97,6 +96,10 @@ async def suggestion_up_vote( ), ephemeral=True, ) + logger.debug( + f"Member {member_id} up voted {suggestion_id}", + extra_metadata={"suggestion_id": suggestion_id}, + ) await update_suggestion_message(suggestion=suggestion, bot=self.bot) @@ -141,11 +144,10 @@ async def suggestion_down_vote( ), ephemeral=True, ) - # log.debug( - # "Member %s modified their vote on %s to a down vote", - # member_id, - # suggestion_id, - # ) + logger.debug( + f"Member {member_id} modified their vote on {suggestion_id} to a down vote", + extra_metadata={"suggestion_id": suggestion_id}, + ) else: suggestion.down_voted_by.add(member_id) await self.state.suggestions_db.upsert(suggestion, suggestion) @@ -156,9 +158,12 @@ async def suggestion_down_vote( ), ephemeral=True, ) + logger.debug( + f"Member {member_id} down voted {suggestion_id}", + extra_metadata={"suggestion_id": suggestion_id}, + ) await update_suggestion_message(suggestion=suggestion, bot=self.bot) - # log.debug("Member %s down voted suggestion %s", member_id, suggestion_id) @components.button_listener() async def queue_approve(self, inter: disnake.MessageInteraction): @@ -280,10 +285,13 @@ async def suggest( qs.channel_id = msg.channel.id await self.bot.db.queued_suggestions.upsert(qs, qs) - log.debug( - "User %s created new queued suggestion in guild %s", - interaction.author.id, - interaction.guild_id, + logger.debug( + f"User {interaction.author.id} created new queued" + f" suggestion in guild {interaction.guild_id}", + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + }, ) return await interaction.send( ephemeral=True, @@ -314,11 +322,14 @@ async def suggest( icon_url=icon_url, ) - log.debug( - "User %s created new suggestion %s in guild %s", - interaction.author.id, - suggestion.suggestion_id, - interaction.guild_id, + logger.debug( + f"User {interaction.author.id} created new suggestion " + f"{suggestion.suggestion_id} in guild {interaction.guild_id}", + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + "suggestion_id": suggestion.suggestion_id, + }, ) await self.stats.log_stats( interaction.author.id, @@ -370,11 +381,14 @@ async def approve( ), ephemeral=True, ) - log.debug( - "User %s approved suggestion %s in guild %s", - interaction.author.id, - suggestion.suggestion_id, - interaction.guild_id, + logger.debug( + f"User {interaction.author.id} approved suggestion " + f"{suggestion.suggestion_id} in guild {interaction.guild_id}", + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + "suggestion_id": suggestion.suggestion_id, + }, ) await self.stats.log_stats( interaction.author.id, @@ -430,11 +444,14 @@ async def reject( ), ephemeral=True, ) - log.debug( - "User %s rejected suggestion %s in guild %s", - interaction.author.id, - suggestion.suggestion_id, - interaction.guild_id, + logger.debug( + f"User {interaction.author} rejected suggestion {suggestion.suggestion_id} " + f"in guild {interaction.guild_id}", + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + "suggestion_id": suggestion.suggestion_id, + }, ) await self.stats.log_stats( interaction.author.id, @@ -492,11 +509,14 @@ async def clear( ), ephemeral=True, ) - log.debug( - "User %s cleared suggestion %s in guild %s", - interaction.user.id, - suggestion_id, - interaction.guild_id, + logger.debug( + f"User {interaction.user.id} cleared suggestion" + f" {suggestion_id} in guild {interaction.guild_id}", + extra_metadata={ + "author_id": interaction.author.id, + "guild_id": interaction.guild_id, + "suggestion_id": suggestion.suggestion_id, + }, ) await self.stats.log_stats( interaction.author.id, @@ -523,9 +543,9 @@ async def get_sid_for( ) else: if not values: - log.debug( - "Values was found, but empty in guild %s thus populating", - interaction.guild_id, + logger.debug( + f"Values was found, but empty in guild {interaction.guild_id} thus populating", + extra_metadata={"guild_id": interaction.guild_id}, ) values: list[str] = await self.state.populate_sid_cache( interaction.guild_id diff --git a/suggestions/cogs/suggestion_queue_cog.py b/suggestions/cogs/suggestion_queue_cog.py index 66c7a8f..5bbe3ab 100644 --- a/suggestions/cogs/suggestion_queue_cog.py +++ b/suggestions/cogs/suggestion_queue_cog.py @@ -1,33 +1,17 @@ from __future__ import annotations -import logging -from datetime import timedelta -from typing import TYPE_CHECKING - import cooldowns import disnake -from alaric import AQ -from alaric.comparison import EQ -from alaric.logical import AND -from alaric.projections import Projection, SHOW -from commons.caching import NonExistentEntry, TimedCache -from disnake import Guild from disnake.ext import commands, components +from logoo import Logger from suggestions import checks from suggestions.cooldown_bucket import InteractionBucket from suggestions.core import SuggestionsQueue -from suggestions.exceptions import ErrorHandled from suggestions.interaction_handler import InteractionHandler -from suggestions.objects import GuildConfig, UserConfig, QueuedSuggestion -from suggestions.qs_paginator import QueuedSuggestionsPaginator -if TYPE_CHECKING: - from alaric import Document - from suggestions import SuggestionsBot - from suggestions.objects import Suggestion -log = logging.getLogger(__name__) +logger = Logger(__name__) class SuggestionsQueueCog(commands.Cog): diff --git a/suggestions/cogs/suggestions_message_commands.py b/suggestions/cogs/suggestions_message_commands.py index 4887ca0..7affd6a 100644 --- a/suggestions/cogs/suggestions_message_commands.py +++ b/suggestions/cogs/suggestions_message_commands.py @@ -1,11 +1,11 @@ from __future__ import annotations -import logging from typing import TYPE_CHECKING import cooldowns import disnake from disnake.ext import commands +from logoo import Logger from suggestions import checks from suggestions.cooldown_bucket import InteractionBucket @@ -15,7 +15,7 @@ if TYPE_CHECKING: from suggestions import SuggestionsBot, State, Stats -log = logging.getLogger(__name__) +logger = Logger(__name__) # noinspection DuplicatedCode @@ -54,11 +54,16 @@ async def approve_suggestion(self, interaction: disnake.GuildCommandInteraction) ), ephemeral=True, ) - log.debug( + logger.debug( "User %s approved suggestion %s in guild %s by message command", interaction.author.id, suggestion.suggestion_id, interaction.guild_id, + extra_metadata={ + "author_id": interaction.author.id, + "suggestion_id": suggestion.suggestion_id, + "guild_id": interaction.guild_id, + }, ) await self.stats.log_stats( interaction.author.id, @@ -93,11 +98,16 @@ async def reject_suggestion(self, interaction: disnake.GuildCommandInteraction): ), ephemeral=True, ) - log.debug( + logger.debug( "User %s rejected suggestion %s in guild %s by message command", interaction.author.id, suggestion.suggestion_id, interaction.guild_id, + extra_metadata={ + "author_id": interaction.author.id, + "suggestion_id": suggestion.suggestion_id, + "guild_id": interaction.guild_id, + }, ) await self.stats.log_stats( interaction.author.id, diff --git a/suggestions/cogs/user_config_cog.py b/suggestions/cogs/user_config_cog.py index 5ac8c10..2af1423 100644 --- a/suggestions/cogs/user_config_cog.py +++ b/suggestions/cogs/user_config_cog.py @@ -1,11 +1,11 @@ from __future__ import annotations -import logging from typing import TYPE_CHECKING import cooldowns import disnake from disnake.ext import commands +from logoo import Logger from suggestions.cooldown_bucket import InteractionBucket from suggestions.objects import UserConfig @@ -13,7 +13,7 @@ if TYPE_CHECKING: from suggestions import SuggestionsBot, State, Stats -log = logging.getLogger(__name__) +logger = Logger(__name__) class UserConfigCog(commands.Cog): @@ -36,7 +36,11 @@ async def enable(self, interaction: disnake.CommandInteraction): user_config.dm_messages_disabled = False await self.bot.db.user_configs.upsert(user_config, user_config) await interaction.send("I have enabled DM messages for you.", ephemeral=True) - log.debug("Enabled DM messages for member %s", interaction.author.id) + logger.debug( + "Enabled DM messages for member %s", + interaction.author.id, + extra_metadata={"author_id": interaction.author.id}, + ) await self.stats.log_stats( interaction.author.id, interaction.guild_id, @@ -52,7 +56,11 @@ async def disable(self, interaction: disnake.CommandInteraction): user_config.dm_messages_disabled = True await self.bot.db.user_configs.upsert(user_config, user_config) await interaction.send("I have disabled DM messages for you.", ephemeral=True) - log.debug("Disabled DM messages for member %s", interaction.author.id) + logger.debug( + "Disabled DM messages for member %s", + interaction.author.id, + extra_metadata={"author_id": interaction.author.id}, + ) await self.stats.log_stats( interaction.author.id, interaction.guild_id, @@ -69,7 +77,11 @@ async def view(self, interaction: disnake.CommandInteraction): await interaction.send( f"I {text} DM you on actions such as suggest.", ephemeral=True ) - log.debug("User %s viewed their DM configuration", interaction.author.id) + logger.debug( + "User %s viewed their DM configuration", + interaction.author.id, + extra_metadata={"author_id": interaction.author.id}, + ) await self.stats.log_stats( interaction.author.id, interaction.guild_id, diff --git a/suggestions/cogs/view_voters_cog.py b/suggestions/cogs/view_voters_cog.py index 7ec3f38..5f7571b 100644 --- a/suggestions/cogs/view_voters_cog.py +++ b/suggestions/cogs/view_voters_cog.py @@ -1,6 +1,5 @@ from __future__ import annotations -import logging from typing import TYPE_CHECKING, Type import cooldowns @@ -8,6 +7,7 @@ from commons.caching import NonExistentEntry from disnake.ext import commands from bot_base.paginators.disnake_paginator import DisnakePaginator +from logoo import Logger from suggestions import Colors from suggestions.cooldown_bucket import InteractionBucket @@ -18,7 +18,7 @@ from alaric import Document from suggestions import SuggestionsBot, State -log = logging.getLogger(__name__) +logger = Logger(__name__) class VoterPaginator(DisnakePaginator): @@ -273,9 +273,10 @@ async def get_sid_for( ) else: if not values: - log.debug( + logger.debug( "Values was found, but empty in guild %s thus populating", interaction.guild_id, + extra_metadata={"guild_id": interaction.guild_id}, ) values: list[str] = await self.state.populate_view_voters_cache( interaction.guild_id diff --git a/suggestions/garven.py b/suggestions/garven.py index bb04931..a74bf83 100644 --- a/suggestions/garven.py +++ b/suggestions/garven.py @@ -5,6 +5,7 @@ from typing import TYPE_CHECKING import aiohttp +from logoo import Logger from suggestions.exceptions import PartialResponse @@ -12,6 +13,7 @@ from suggestions import SuggestionsBot log = logging.getLogger(__name__) +logger = Logger(__name__) class Garven: @@ -57,7 +59,7 @@ async def notify_devs(self, *, title: str, description: str, sender: str): }, ) as resp: if resp.status != 204: - log.error( + logger.error( "Error when attempting to notify devs\n\t- %s", await resp.text(), ) diff --git a/suggestions/objects/guild_config.py b/suggestions/objects/guild_config.py index 027596e..0ec6b55 100644 --- a/suggestions/objects/guild_config.py +++ b/suggestions/objects/guild_config.py @@ -1,16 +1,16 @@ from __future__ import annotations -import logging from typing import TYPE_CHECKING, Dict, Optional from alaric import AQ from alaric.comparison import EQ from commons.caching import NonExistentEntry +from logoo import Logger if TYPE_CHECKING: from suggestions import State -log = logging.getLogger(__name__) +logger = Logger(__name__) class GuildConfig: @@ -74,7 +74,11 @@ async def from_id(cls, guild_id: int, state: State) -> GuildConfig: """ try: gc = state.guild_configs.get_entry(guild_id) - log.debug("Found cached GuildConfig for guild %s", guild_id) + logger.debug( + "Found cached GuildConfig for guild %s", + guild_id, + extra_metadata={"guild_id": guild_id}, + ) return gc except NonExistentEntry: pass @@ -83,7 +87,11 @@ async def from_id(cls, guild_id: int, state: State) -> GuildConfig: AQ(EQ("_id", guild_id)) ) if not guild_config: - log.info("Created new GuildConfig for %s", guild_id) + logger.info( + "Created new GuildConfig for %s", + guild_id, + extra_metadata={"guild_id": guild_id}, + ) guild_config = cls(_id=guild_id) state.refresh_guild_config(guild_config) diff --git a/suggestions/objects/queued_suggestion.py b/suggestions/objects/queued_suggestion.py index 67212a6..a84606d 100644 --- a/suggestions/objects/queued_suggestion.py +++ b/suggestions/objects/queued_suggestion.py @@ -1,13 +1,13 @@ from __future__ import annotations import datetime -import logging -from typing import Optional, TYPE_CHECKING, overload +from typing import Optional, TYPE_CHECKING from alaric import AQ from alaric.comparison import EQ from alaric.logical import AND from disnake import Embed +from logoo import Logger from suggestions.exceptions import UnhandledError, SuggestionNotFound from suggestions.objects import Suggestion @@ -15,7 +15,7 @@ if TYPE_CHECKING: from suggestions import State, SuggestionsBot -log = logging.getLogger(__name__) +logger = Logger(__name__) class QueuedSuggestion: @@ -224,7 +224,7 @@ async def convert_to_suggestion(self, state: State) -> Suggestion: # the database and is then disregarded # 2. When we get here the object should have been retrieved # via the queue system so the object should have an attached id - log.critical("QueuedSuggestion(%s) does not have an id", self.as_dict()) + logger.critical("QueuedSuggestion(%s) does not have an id", self.as_dict()) raise UnhandledError( f"QueuedSuggestion({self.as_dict()}) does not have an id" ) diff --git a/suggestions/objects/stats/member_stats.py b/suggestions/objects/stats/member_stats.py index fed9334..52e9925 100644 --- a/suggestions/objects/stats/member_stats.py +++ b/suggestions/objects/stats/member_stats.py @@ -1,6 +1,5 @@ from __future__ import annotations -import logging from datetime import datetime from typing import TYPE_CHECKING, Dict, List, Optional @@ -8,13 +7,14 @@ from alaric.comparison import EQ from alaric.logical import AND from commons.caching import NonExistentEntry +from logoo import Logger from .member_command_stats import MemberCommandStats if TYPE_CHECKING: from suggestions import State, Stats -log = logging.getLogger(__name__) +logger = Logger(__name__) class MemberStats: @@ -112,10 +112,11 @@ async def from_id(cls, member_id: int, guild_id: int, state: State) -> MemberSta stats.refresh_member_stats(member_stats) return member_stats - log.debug( + logger.debug( "Getting fresh MemberStats object for %s in guild %s", member_id, guild_id, + extra_metadata={"guild_id": guild_id, "author_id": member_id}, ) instance = cls(member_id, guild_id) stats.refresh_member_stats(instance) diff --git a/suggestions/objects/suggestion.py b/suggestions/objects/suggestion.py index ea04c70..5b75382 100644 --- a/suggestions/objects/suggestion.py +++ b/suggestions/objects/suggestion.py @@ -1,7 +1,6 @@ from __future__ import annotations import datetime -import logging from enum import Enum from typing import TYPE_CHECKING, Literal, Union, Optional, cast @@ -12,6 +11,7 @@ from bot_base.wraps import WrappedChannel from disnake import Embed, Guild from disnake.ext import commands +from logoo import Logger from suggestions import ErrorCode from suggestions.exceptions import ErrorHandled, SuggestionNotFound @@ -21,7 +21,7 @@ if TYPE_CHECKING: from suggestions import SuggestionsBot, State, Colors -log = logging.getLogger(__name__) +logger = Logger(__name__) class SuggestionState(Enum): @@ -285,8 +285,10 @@ async def from_id( ) if suggestion.guild_id != guild_id: - log.critical( - "Someone in guild %s looked up a suggestion not from their guild" + logger.critical( + "Someone in guild %s looked up a suggestion not from their guild", + guild_id, + extra_metadata={"guild_id": guild_id, "suggestion_id": suggestion_id}, ) raise SuggestionNotFound( f"No suggestion found with the id {suggestion_id} in this guild" @@ -606,7 +608,11 @@ async def save_reaction_results( self._total_down_votes = reaction.count - 1 if self.total_up_votes is None or self.total_down_votes is None: - log.error("Failed to find our emojis on suggestion %s", self.suggestion_id) + logger.error( + "Failed to find our emojis on suggestion %s", + self.suggestion_id, + extra_metadata={"suggestion_id": self.suggestion_id}, + ) await bot.db.suggestions.update(self, self) @@ -615,20 +621,29 @@ async def try_notify_user_of_decision(self, bot: SuggestionsBot): self.suggestion_author_id, bot.state ) if user_config.dm_messages_disabled: - log.debug( + logger.debug( "User %s has dm messages disabled, failed to notify change to suggestion %s", self.suggestion_author_id, self.suggestion_id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "author_id": self.suggestion_author_id, + }, ) return guild_config: GuildConfig = await GuildConfig.from_id(self.guild_id, bot.state) if guild_config.dm_messages_disabled: - log.debug( + logger.debug( "Guild %s has dm messages disabled, failed to notify user %s regarding changes to suggestion %s", self.guild_id, self.suggestion_author_id, self.suggestion_id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "author_id": self.suggestion_author_id, + "guild_id": self.guild_id, + }, ) return @@ -660,7 +675,14 @@ async def try_notify_user_of_decision(self, bot: SuggestionsBot): try: await user.send(embed=embed) except disnake.HTTPException: - log.debug("Failed to dm %s to tell them about their suggestion", user.id) + logger.debug( + "Failed to dm %s to tell them about their suggestion", + user.id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "author_id": user.id, + }, + ) async def create_thread(self, message: disnake.Message): """Create a thread for this suggestion""" @@ -677,11 +699,15 @@ async def update_vote_count( interaction: disnake.Interaction, ): if self.channel_id is None or self.message_id is None: - log.error( + logger.error( "update_vote_count received a null value for SID %s, " "channel_id=%s, message_id=%s", self.channel_id, self.message_id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "author_id": self.suggestion_author_id, + }, ) return @@ -767,35 +793,54 @@ async def archive_thread_if_required( """Attempts to archive the attached thread if the feature is enabled.""" if not guild_config.auto_archive_threads: # Guild does not want thread archived - log.debug("Guild %s does not want threads archived", guild_config.guild_id) + logger.debug( + "Guild %s does not want threads archived", + guild_config.guild_id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "guild_id": self.guild_id, + }, + ) return channel: WrappedChannel = await bot.get_or_fetch_channel(self.channel_id) message: disnake.Message = await channel.fetch_message(self.message_id) if not message.thread: # Suggestion has no created thread - log.debug( + logger.debug( "No thread for suggestion %s, should have one: %s", self.suggestion_id, "yes" if guild_config.threads_for_suggestions else "no", + extra_metadata={ + "suggestion_id": self.suggestion_id, + "guild_id": self.guild_id, + }, ) return if message.thread.owner_id != bot.user.id: # I did not create this thread - log.debug( + logger.debug( "Thread on suggestion %s is owned by %s", self.suggestion_id, message.thread.owner_id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "guild_id": self.guild_id, + }, ) return if message.thread.archived or message.thread.locked: # Thread is already archived or # locked so no need to redo the action - log.debug( + logger.debug( "Thread on suggestion %s is already archived or locked", self.suggestion_id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "guild_id": self.guild_id, + }, ) return @@ -803,7 +848,14 @@ async def archive_thread_if_required( bot.get_locale("SUGGESTION_OBJECT_LOCK_THREAD", locale), ) await message.thread.edit(locked=True, archived=True) - log.debug("Locked thread for suggestion %s", self.suggestion_id) + logger.debug( + "Locked thread for suggestion %s", + self.suggestion_id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "guild_id": self.guild_id, + }, + ) async def resolve( self, @@ -814,7 +866,14 @@ async def resolve( resolution_type: SuggestionState, resolution_note: Optional[str] = None, ): - log.debug("Attempting to resolve suggestion %s", self.suggestion_id) + logger.debug( + "Attempting to resolve suggestion %s", + self.suggestion_id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "guild_id": self.guild_id, + }, + ) self.anonymous_resolution = guild_config.anonymous_resolutions # https://github.com/suggestionsbot/suggestions-bot/issues/36 if resolution_type is SuggestionState.approved: @@ -822,10 +881,14 @@ async def resolve( elif resolution_type is SuggestionState.rejected: await self.mark_rejected_by(state, interaction.author.id, resolution_note) else: - log.error( + logger.error( "Resolving suggestion %s received a resolution_type of %s", self.suggestion_id, resolution_type, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "guild_id": self.guild_id, + }, ) await interaction.send( embed=bot.error_embed( @@ -882,7 +945,14 @@ async def setup_initial_messages( ), ], ) - log.debug("Sent suggestion %s to channel", self.suggestion_id) + logger.debug( + "Sent suggestion %s to channel", + self.suggestion_id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "guild_id": self.guild_id, + }, + ) except disnake.Forbidden as e: state.remove_sid_from_cache(interaction.guild_id, self.suggestion_id) await state.suggestions_db.delete(self.as_filter()) @@ -896,9 +966,13 @@ async def setup_initial_messages( try: await self.create_thread(message) except disnake.HTTPException: - log.debug( + logger.debug( "Failed to create a thread on suggestion %s", self.suggestion_id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "guild_id": self.guild_id, + }, ) did_delete = await self.try_delete( bot=bot, interaction=interaction, silently=True @@ -922,7 +996,14 @@ async def setup_initial_messages( raise ErrorHandled else: - log.debug("Created a thread on suggestion %s", self.suggestion_id) + logger.debug( + "Created a thread on suggestion %s", + self.suggestion_id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "guild_id": self.guild_id, + }, + ) try: suggestion_author = ( @@ -964,9 +1045,14 @@ async def setup_initial_messages( or guild_config.dm_messages_disabled ): # Nothing we can do - log.debug( + logger.debug( "Failed to DM %s regarding their suggestion being created from queue", self.suggestion_author_id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "guild_id": self.guild_id, + "author_id": self.suggestion_author_id, + }, ) return @@ -987,7 +1073,12 @@ async def setup_initial_messages( ) await interaction.author.send(embed=embed) except disnake.HTTPException: - log.debug( + logger.debug( "Failed to DM %s regarding their suggestion", interaction.author.id, + extra_metadata={ + "suggestion_id": self.suggestion_id, + "guild_id": self.guild_id, + "author_id": interaction.author.id, + }, ) diff --git a/suggestions/objects/user_config.py b/suggestions/objects/user_config.py index 580f556..4c647a0 100644 --- a/suggestions/objects/user_config.py +++ b/suggestions/objects/user_config.py @@ -1,16 +1,16 @@ from __future__ import annotations -import logging from typing import Dict, TYPE_CHECKING, Optional from alaric import AQ from alaric.comparison import EQ from commons.caching import NonExistentEntry +from logoo import Logger if TYPE_CHECKING: from suggestions import State -log = logging.getLogger(__name__) +logger = Logger(__name__) class UserConfig: @@ -24,7 +24,11 @@ def __init__(self, _id: int, dm_messages_disabled: bool = False): async def from_id(cls, user_id: int, state: State): try: uc = state.user_configs.get_entry(user_id) - log.debug("Found cached UserConfig for user %s", user_id) + logger.debug( + "Found cached UserConfig for user %s", + user_id, + extra_metadata={"author_id": user_id}, + ) return uc except NonExistentEntry: pass @@ -33,12 +37,17 @@ async def from_id(cls, user_id: int, state: State): AQ(EQ("_id", user_id)) ) if not user_config: - log.info("Created new UserConfig for %s", user_id) + logger.info( + "Created new UserConfig for %s", + user_id, + extra_metadata={"author_id": user_id}, + ) user_config = cls(_id=user_id) else: - log.debug( + logger.debug( "Fetched UserConfig from database for %s", user_id, + extra_metadata={"author_id": user_id}, ) state.refresh_user_config(user_config) diff --git a/suggestions/qs_paginator.py b/suggestions/qs_paginator.py index d8a7894..49e9470 100644 --- a/suggestions/qs_paginator.py +++ b/suggestions/qs_paginator.py @@ -1,12 +1,12 @@ from __future__ import annotations -import logging from typing import TYPE_CHECKING import disnake from alaric import AQ from alaric.comparison import EQ from alaric.logical import AND +from logoo import Logger from suggestions.exceptions import QueueImbalance from suggestions.objects import QueuedSuggestion @@ -15,7 +15,7 @@ from suggestions import SuggestionsBot -log = logging.getLogger(__name__) +logger = Logger(__name__) class QueuedSuggestionsPaginator: @@ -78,7 +78,13 @@ async def format_page(self) -> disnake.Embed: suggestion: QueuedSuggestion = await self.get_current_queued_suggestion() except QueueImbalance: await self.remove_current_page() - log.debug("Hit QueueImbalance") + logger.warning( + "Hit QueueImbalance", + extra_metadata={ + "author_id": self.original_interaction.author.id, + "guild_id": self.original_interaction.guild_id, + }, + ) else: embed: disnake.Embed = await suggestion.as_embed(self.bot) if suggestion.is_anonymous: diff --git a/suggestions/scheduler.py b/suggestions/scheduler.py index 2ea259b..0552aa6 100644 --- a/suggestions/scheduler.py +++ b/suggestions/scheduler.py @@ -1,7 +1,10 @@ import asyncio import logging +from logoo import Logger + log = logging.getLogger(__name__) +logger = Logger(__name__) # Modified from https://stackoverflow.com/a/55185488 @@ -25,7 +28,7 @@ async def inner_task(caller, *args, **kwargs): await asyncio.sleep(sleep_between_tries) - log.debug( + logger.debug( "exception_aware_scheduler for %s has run out of retries", str(caller) ) diff --git a/suggestions/state.py b/suggestions/state.py index cd24e41..86705cc 100644 --- a/suggestions/state.py +++ b/suggestions/state.py @@ -15,8 +15,7 @@ from alaric.meta import Negate from alaric.projections import PROJECTION, SHOW from commons.caching import NonExistentEntry, TimedCache -from disnake import Thread -from disnake.abc import GuildChannel, PrivateChannel +from logoo import Logger from suggestions.objects import GuildConfig, UserConfig @@ -27,6 +26,7 @@ from suggestions.interaction_handler import InteractionHandler log = logging.getLogger(__name__) +logger = Logger(__name__) class State: @@ -92,7 +92,7 @@ def get_new_error_id(self) -> str: error_id = "".join( random.choices(string.ascii_lowercase + string.digits, k=8) ) - log.critical("Encountered an existing error id") + logger.critical("Encountered an existing error id") self.existing_error_ids.add(error_id) return error_id @@ -103,7 +103,7 @@ def get_new_sq_paginator_id(self) -> str: pag_id = "".join( random.choices(string.ascii_lowercase + string.digits, k=8) ) - log.critical("Encountered an existing paginator id") + logger.critical("Encountered an existing paginator id") self.existing_paginator_ids.add(pag_id) return pag_id @@ -117,7 +117,7 @@ def get_new_suggestion_id(self) -> str: suggestion_id = "".join( random.choices(string.ascii_lowercase + string.digits, k=8) ) - log.critical("Encountered an existing SID") + logger.critical("Encountered an existing SID") self.existing_suggestion_ids.add(suggestion_id) return suggestion_id @@ -178,7 +178,11 @@ async def populate_sid_cache(self, guild_id: int) -> list: ) data: List[str] = [d["_id"] for d in data] self.autocomplete_cache.add_entry(guild_id, data, override=True) - log.debug("Populated sid cache for guild %s", guild_id) + logger.debug( + "Populated sid cache for guild %s", + guild_id, + extra_metadata={"guild_id": guild_id}, + ) return data async def populate_view_voters_cache(self, guild_id: int) -> list: @@ -190,7 +194,11 @@ async def populate_view_voters_cache(self, guild_id: int) -> list: ) data: List[str] = [d["_id"] for d in data] self.view_voters_cache.add_entry(guild_id, data, override=True) - log.debug("Populated view voter cache for guild %s", guild_id) + logger.debug( + "Populated view voter cache for guild %s", + guild_id, + extra_metadata={"guild_id": guild_id}, + ) return data def add_sid_to_cache(self, guild_id: int, suggestion_id: str) -> None: @@ -208,7 +216,12 @@ def add_sid_to_cache(self, guild_id: int, suggestion_id: str) -> None: finally: self.autocomplete_cache.add_entry(guild_id, current_values, override=True) - log.debug("Added sid %s to cache for guild %s", suggestion_id, guild_id) + logger.debug( + "Added sid %s to cache for guild %s", + suggestion_id, + guild_id, + extra_metadata={"guild_id": guild_id, "suggestion_id": suggestion_id}, + ) def remove_sid_from_cache(self, guild_id: int, suggestion_id: str) -> None: """Removes a suggestion from the cache when it's state is no longer open.""" @@ -227,10 +240,14 @@ def remove_sid_from_cache(self, guild_id: int, suggestion_id: str) -> None: current_values, override=True, ) - log.debug( + logger.debug( "Removed sid %s from the cache for guild %s", suggestion_id, guild_id, + extra_metadata={ + "guild_id": guild_id, + "suggestion_id": suggestion_id, + }, ) async def load(self): diff --git a/suggestions/utility/r2.py b/suggestions/utility/r2.py index 1a886f6..f48c775 100644 --- a/suggestions/utility/r2.py +++ b/suggestions/utility/r2.py @@ -1,14 +1,14 @@ import hashlib -import logging import mimetypes import os import secrets from aiobotocore.session import get_session +from logoo import Logger from suggestions.exceptions import InvalidFileType -log = logging.getLogger(__name__) +logger = Logger(__name__) async def upload_file_to_r2( @@ -52,6 +52,16 @@ async def upload_file_to_r2( file_key = hashlib.sha256(file_data + secrets.token_bytes(16)).hexdigest() key = "{}/{}.{}".format(guild_id, file_key, ext) await client.put_object(Bucket=os.environ["BUCKET"], Key=key, Body=file_data) - log.debug("User %s in guild %s uploaded an image", user_id, guild_id) + logger.debug( + "User %s in guild %s uploaded an image", + user_id, + guild_id, + extra_metadata={ + "author_id": user_id, + "guild_id": guild_id, + "original_image_name": file_name, + "uploaded_to": key, + }, + ) return f"https://cdn.suggestions.bot/{key}"