From 6a388f3eaabab0dec4327aedb792e7a326a1e4a4 Mon Sep 17 00:00:00 2001 From: Dimosthenis Schizas Date: Mon, 5 Oct 2026 17:43:06 +0300 Subject: [PATCH 1/4] fix(bot): log a missing guild member without a traceback A member who left the guild is an expected case in get_member_or_user, and the code falls back to the user lookup. It logged a full traceback at WARNING, which produced dozens of tracebacks on every start when scheduled unbans and unmutes were re-created. It now logs one DEBUG line with the id. Forbidden, HTTP errors and a missing user still log with the traceback. The user lookup messages now say user instead of guild member. --- src/bot.py | 19 +++--- tests/src/test_bot.py | 130 ++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 139 insertions(+), 10 deletions(-) create mode 100644 tests/src/test_bot.py diff --git a/src/bot.py b/src/bot.py index 6f004f56..3b64957a 100644 --- a/src/bot.py +++ b/src/bot.py @@ -1,5 +1,6 @@ import logging import socket +from typing import TypeVar import discord from aiohttp import AsyncResolver, ClientSession, TCPConnector @@ -27,7 +28,6 @@ UserInputError, ) from sqlalchemy.exc import NoResultFound -from typing import TypeVar from src import trace_config from src.core import constants, settings @@ -136,14 +136,14 @@ async def on_application_command_error( elif isinstance(error, CommandOnCooldown): message = f"You are on cooldown. Try again in {error.retry_after:.2f}s" elif isinstance(error, NoResultFound): - message = f"The requested object could not be found." + message = "The requested object could not be found." errored_commands.labels(ctx.command.name).inc() if message is None: raise error else: - logger.debug(f"A user caused an error which was handled.", exc_info=error) + logger.debug("A user caused an error which was handled.", exc_info=error) await ctx.respond(message, delete_after=15, ephemeral=True) async def on_application_command_completion(self, ctx: ApplicationContext) -> None: @@ -204,21 +204,20 @@ async def get_member_or_user(self, guild: Guild, id_: int) -> Member | User | No logger.warning( f"Unauthorized attempt to fetch member with id: {id_}", exc_info=exc ) - except NotFound as exc: - logger.warning(f"Could not find guild member with id: {id_}", exc_info=exc) + except NotFound: + # Expected for users who left the guild, so no traceback; we fall back to the user lookup. + logger.debug(f"Could not find guild member with id: {id_}") try: return await self.get_or_fetch_user(id_) except Forbidden as exc: logger.warning( - f"Unauthorized attempt to fetch member with id: {id_}", exc_info=exc + f"Unauthorized attempt to fetch user with id: {id_}", exc_info=exc ) except NotFound as exc: - logger.warning( - f"Could not find guild member with id: {id_}", exc_info=exc - ) + logger.warning(f"Could not find user with id: {id_}", exc_info=exc) except HTTPException as exc: logger.error( - f"Discord error while fetching guild member with id: {id_}", + f"Discord error while fetching user with id: {id_}", exc_info=exc, ) except HTTPException as exc: diff --git a/tests/src/test_bot.py b/tests/src/test_bot.py new file mode 100644 index 00000000..55a67095 --- /dev/null +++ b/tests/src/test_bot.py @@ -0,0 +1,130 @@ +import logging +from unittest.mock import AsyncMock, MagicMock + +import pytest +from discord import Forbidden, HTTPException, NotFound + +from src.bot import Bot + +USER_ID = 123456789 + + +@pytest.fixture(autouse=True) +def enabled_bot_logger(monkeypatch): + # The alembic migration tests call logging.config.fileConfig, which disables existing loggers. + monkeypatch.setattr(logging.getLogger("src.bot"), "disabled", False) + + +def _response(status: int) -> MagicMock: + response = MagicMock() + response.status = status + response.reason = "reason" + return response + + +def _bot(fetch_member_error: Exception | None = None, user_result=None) -> MagicMock: + bot = MagicMock() + bot.guild = MagicMock() + bot.guild.fetch_member = AsyncMock(side_effect=fetch_member_error, return_value="member") + if isinstance(user_result, Exception): + bot.get_or_fetch_user = AsyncMock(side_effect=user_result) + else: + bot.get_or_fetch_user = AsyncMock(return_value=user_result) + return bot + + +def _records(caplog): + return [r for r in caplog.records if r.name == "src.bot"] + + +class TestGetMemberOrUser: + @pytest.mark.asyncio + async def test_returns_member(self, caplog): + bot = _bot() + with caplog.at_level(logging.DEBUG, logger="src.bot"): + result = await Bot.get_member_or_user(bot, bot.guild, USER_ID) + + assert result == "member" + assert _records(caplog) == [] + + @pytest.mark.asyncio + async def test_member_not_in_guild_falls_back_to_user_without_traceback(self, caplog): + bot = _bot(NotFound(_response(404), "Unknown Member"), user_result="user") + with caplog.at_level(logging.DEBUG, logger="src.bot"): + result = await Bot.get_member_or_user(bot, bot.guild, USER_ID) + + assert result == "user" + bot.get_or_fetch_user.assert_awaited_once_with(USER_ID) + records = _records(caplog) + assert len(records) == 1 + assert records[0].levelno == logging.DEBUG + assert records[0].getMessage() == f"Could not find guild member with id: {USER_ID}" + assert records[0].exc_info is None + + @pytest.mark.asyncio + async def test_member_and_user_not_found_keeps_traceback(self, caplog): + user_error = NotFound(_response(404), "Unknown User") + bot = _bot(NotFound(_response(404), "Unknown Member"), user_result=user_error) + with caplog.at_level(logging.DEBUG, logger="src.bot"): + result = await Bot.get_member_or_user(bot, bot.guild, USER_ID) + + assert result is None + warnings = [r for r in _records(caplog) if r.levelno == logging.WARNING] + assert len(warnings) == 1 + assert warnings[0].getMessage() == f"Could not find user with id: {USER_ID}" + assert warnings[0].exc_info[1] is user_error + + @pytest.mark.asyncio + async def test_forbidden_fetching_member_keeps_traceback(self, caplog): + error = Forbidden(_response(403), "Missing Access") + bot = _bot(error) + with caplog.at_level(logging.DEBUG, logger="src.bot"): + result = await Bot.get_member_or_user(bot, bot.guild, USER_ID) + + assert result is None + bot.get_or_fetch_user.assert_not_awaited() + records = _records(caplog) + assert len(records) == 1 + assert records[0].levelno == logging.WARNING + assert records[0].getMessage() == f"Unauthorized attempt to fetch member with id: {USER_ID}" + assert records[0].exc_info[1] is error + + @pytest.mark.asyncio + async def test_forbidden_fetching_user_after_member_not_found_keeps_traceback(self, caplog): + error = Forbidden(_response(403), "Missing Access") + bot = _bot(NotFound(_response(404), "Unknown Member"), user_result=error) + with caplog.at_level(logging.DEBUG, logger="src.bot"): + result = await Bot.get_member_or_user(bot, bot.guild, USER_ID) + + assert result is None + warnings = [r for r in _records(caplog) if r.levelno == logging.WARNING] + assert len(warnings) == 1 + assert warnings[0].getMessage() == f"Unauthorized attempt to fetch user with id: {USER_ID}" + assert warnings[0].exc_info[1] is error + + @pytest.mark.asyncio + async def test_http_error_after_member_not_found_logs_error_with_traceback(self, caplog): + error = HTTPException(_response(500), "boom") + bot = _bot(NotFound(_response(404), "Unknown Member"), user_result=error) + with caplog.at_level(logging.DEBUG, logger="src.bot"): + result = await Bot.get_member_or_user(bot, bot.guild, USER_ID) + + assert result is None + errors = [r for r in _records(caplog) if r.levelno == logging.ERROR] + assert len(errors) == 1 + assert errors[0].getMessage() == f"Discord error while fetching user with id: {USER_ID}" + assert errors[0].exc_info[1] is error + + @pytest.mark.asyncio + async def test_http_error_fetching_member_falls_back_to_user(self, caplog): + error = HTTPException(_response(500), "boom") + bot = _bot(error, user_result="user") + with caplog.at_level(logging.DEBUG, logger="src.bot"): + result = await Bot.get_member_or_user(bot, bot.guild, USER_ID) + + assert result == "user" + records = _records(caplog) + assert len(records) == 1 + assert records[0].levelno == logging.ERROR + assert records[0].getMessage() == f"Discord error while fetching guild member with id: {USER_ID}" + assert records[0].exc_info[1] is error From 1340498ab7f8e3c0f00c36943b2d4aed8c267e58 Mon Sep 17 00:00:00 2001 From: Dimosthenis Schizas Date: Mon, 5 Oct 2026 18:00:57 +0300 Subject: [PATCH 2/4] fix(bot): keep the missing guild member log at WARNING The level stays as it was. Only the traceback goes. --- src/bot.py | 2 +- tests/src/test_bot.py | 18 +++++++++++------- 2 files changed, 12 insertions(+), 8 deletions(-) diff --git a/src/bot.py b/src/bot.py index 3b64957a..99f04b1b 100644 --- a/src/bot.py +++ b/src/bot.py @@ -206,7 +206,7 @@ async def get_member_or_user(self, guild: Guild, id_: int) -> Member | User | No ) except NotFound: # Expected for users who left the guild, so no traceback; we fall back to the user lookup. - logger.debug(f"Could not find guild member with id: {id_}") + logger.warning(f"Could not find guild member with id: {id_}") try: return await self.get_or_fetch_user(id_) except Forbidden as exc: diff --git a/tests/src/test_bot.py b/tests/src/test_bot.py index 55a67095..000a2491 100644 --- a/tests/src/test_bot.py +++ b/tests/src/test_bot.py @@ -57,7 +57,7 @@ async def test_member_not_in_guild_falls_back_to_user_without_traceback(self, ca bot.get_or_fetch_user.assert_awaited_once_with(USER_ID) records = _records(caplog) assert len(records) == 1 - assert records[0].levelno == logging.DEBUG + assert records[0].levelno == logging.WARNING assert records[0].getMessage() == f"Could not find guild member with id: {USER_ID}" assert records[0].exc_info is None @@ -70,9 +70,11 @@ async def test_member_and_user_not_found_keeps_traceback(self, caplog): assert result is None warnings = [r for r in _records(caplog) if r.levelno == logging.WARNING] - assert len(warnings) == 1 - assert warnings[0].getMessage() == f"Could not find user with id: {USER_ID}" - assert warnings[0].exc_info[1] is user_error + assert len(warnings) == 2 + assert warnings[0].getMessage() == f"Could not find guild member with id: {USER_ID}" + assert warnings[0].exc_info is None + assert warnings[1].getMessage() == f"Could not find user with id: {USER_ID}" + assert warnings[1].exc_info[1] is user_error @pytest.mark.asyncio async def test_forbidden_fetching_member_keeps_traceback(self, caplog): @@ -98,9 +100,11 @@ async def test_forbidden_fetching_user_after_member_not_found_keeps_traceback(se assert result is None warnings = [r for r in _records(caplog) if r.levelno == logging.WARNING] - assert len(warnings) == 1 - assert warnings[0].getMessage() == f"Unauthorized attempt to fetch user with id: {USER_ID}" - assert warnings[0].exc_info[1] is error + assert len(warnings) == 2 + assert warnings[0].getMessage() == f"Could not find guild member with id: {USER_ID}" + assert warnings[0].exc_info is None + assert warnings[1].getMessage() == f"Unauthorized attempt to fetch user with id: {USER_ID}" + assert warnings[1].exc_info[1] is error @pytest.mark.asyncio async def test_http_error_after_member_not_found_logs_error_with_traceback(self, caplog): From 6272eea2e2e77741cff4c92e5779e69baf6cd2f4 Mon Sep 17 00:00:00 2001 From: Dimosthenis Schizas Date: Mon, 5 Oct 2026 18:12:17 +0300 Subject: [PATCH 3/4] fix(logging): log warnings without a traceback A warning is a handled condition, so a traceback only buries real errors. No logger.warning call in src/ passes exc_info any more, and a test fails if one does. Errors keep their traceback. The dynamic role reload warning had only the traceback to explain what failed, so its message now includes the exception text. --- src/bot.py | 31 ++++++----------- src/helpers/ban.py | 45 +++++++------------------ src/services/role_manager.py | 4 +-- tests/src/services/__init__.py | 0 tests/src/services/test_role_manager.py | 32 ++++++++++++++++++ tests/src/test_bot.py | 12 +++---- tests/src/test_logging_rules.py | 22 ++++++++++++ 7 files changed, 85 insertions(+), 61 deletions(-) create mode 100644 tests/src/services/__init__.py create mode 100644 tests/src/services/test_role_manager.py create mode 100644 tests/src/test_logging_rules.py diff --git a/src/bot.py b/src/bot.py index 99f04b1b..bfa97cfd 100644 --- a/src/bot.py +++ b/src/bot.py @@ -81,7 +81,7 @@ async def on_ready(self) -> None: try: await self.role_manager.reload() except Exception: - logger.warning("Failed to reload dynamic roles on reconnect, keeping previous cache", exc_info=True) + logger.warning("Failed to reload dynamic roles on reconnect, keeping previous cache") logger.info(f"Started bot as {name}") print("Loading ScheduledTasks cog...") @@ -200,21 +200,16 @@ async def get_member_or_user(self, guild: Guild, id_: int) -> Member | User | No """Get a member or a user from the guild or discord.""" try: return await guild.fetch_member(id_) - except Forbidden as exc: - logger.warning( - f"Unauthorized attempt to fetch member with id: {id_}", exc_info=exc - ) + except Forbidden: + logger.warning(f"Unauthorized attempt to fetch member with id: {id_}") except NotFound: - # Expected for users who left the guild, so no traceback; we fall back to the user lookup. logger.warning(f"Could not find guild member with id: {id_}") try: return await self.get_or_fetch_user(id_) - except Forbidden as exc: - logger.warning( - f"Unauthorized attempt to fetch user with id: {id_}", exc_info=exc - ) - except NotFound as exc: - logger.warning(f"Could not find user with id: {id_}", exc_info=exc) + except Forbidden: + logger.warning(f"Unauthorized attempt to fetch user with id: {id_}") + except NotFound: + logger.warning(f"Could not find user with id: {id_}") except HTTPException as exc: logger.error( f"Discord error while fetching user with id: {id_}", @@ -227,14 +222,10 @@ async def get_member_or_user(self, guild: Guild, id_: int) -> Member | User | No ) try: return await self.get_or_fetch_user(id_) - except Forbidden as exc: - logger.warning( - f"Unauthorized attempt to fetch member with id: {id_}", exc_info=exc - ) - except NotFound as exc: - logger.warning( - f"Could not find guild member with id: {id_}", exc_info=exc - ) + except Forbidden: + logger.warning(f"Unauthorized attempt to fetch member with id: {id_}") + except NotFound: + logger.warning(f"Could not find guild member with id: {id_}") except HTTPException as exc: logger.error( f"Discord error while fetching guild member with id: {id_}", diff --git a/src/helpers/ban.py b/src/helpers/ban.py index 77954c71..1da5b9eb 100644 --- a/src/helpers/ban.py +++ b/src/helpers/ban.py @@ -6,16 +6,7 @@ from enum import Enum import discord -from discord import ( - Forbidden, - Guild, - HTTPException, - Member, - NotFound, - User, - TextChannel, - ClientUser, -) +from discord import ClientUser, Forbidden, Guild, HTTPException, Member, NotFound, TextChannel, User from sqlalchemy import select from sqlalchemy.exc import NoResultFound @@ -354,10 +345,9 @@ async def ban_member_with_epoch( # Try to actually ban the member from the guild try: await guild.ban(member, reason=reason, delete_message_seconds=0) - except Forbidden as exc: + except Forbidden: logger.warning( "Ban failed due to permission error", - exc_info=exc, extra={"ban_requestor": author.name, "ban_receiver": member.id}, ) if author: @@ -367,10 +357,8 @@ async def ban_member_with_epoch( code=BanCodes.FAILED, ) return - except HTTPException as ex: - logger.warning( - f"HTTPException when trying to ban user with ID {member.id}", exc_info=ex - ) + except HTTPException: + logger.warning(f"HTTPException when trying to ban user with ID {member.id}") if author: return SimpleResponse( message="Here's a 400 Bad Request for you. Just like when you tried to ask me out, last week.", @@ -473,16 +461,13 @@ async def _dm_banned_member( try: await member.send(message) return True - except Forbidden as ex: + except Forbidden: logger.warning( f"Could not DM member with id {member.id} due to privacy settings, however will still attempt to ban " - f"them...", - exc_info=ex, - ) - except HTTPException as ex: - logger.warning( - f"HTTPException when trying to unban user with ID {member.id}", exc_info=ex + f"them..." ) + except HTTPException: + logger.warning(f"HTTPException when trying to unban user with ID {member.id}") return False @@ -616,17 +601,11 @@ async def add_infraction( f"After a total value of 3, permanent exclusion from the server may be enforced.\n" f"Following is the reason given:\n>>> {reason}\n" ) - except Forbidden as ex: + except Forbidden: message = "Could not DM member due to privacy settings, however the infraction was still added." - logger.warning( - f"Forbidden, when trying to contact user with ID {member.id} about infraction.", - exc_info=ex, - ) - except HTTPException as ex: + logger.warning(f"Forbidden, when trying to contact user with ID {member.id} about infraction.") + except HTTPException: message = "Here's a 400 Bad Request for you. Just like when you tried to ask me out, last week." - logger.warning( - f"HTTPException when trying to add infraction for user with ID {member.id}", - exc_info=ex, - ) + logger.warning(f"HTTPException when trying to add infraction for user with ID {member.id}") return SimpleResponse(message=message, delete_after=None) diff --git a/src/services/role_manager.py b/src/services/role_manager.py index 07392ddd..7159a3fd 100644 --- a/src/services/role_manager.py +++ b/src/services/role_manager.py @@ -104,9 +104,9 @@ async def load(self) -> None: total = sum(len(v) for v in self._roles.values()) logger.info(f"Loaded {total} dynamic roles from database") - except Exception: + except Exception as exc: if self._loaded: - logger.warning("Failed to reload dynamic roles from DB, keeping previous cache", exc_info=True) + logger.warning(f"Failed to reload dynamic roles from DB, keeping previous cache: {exc}") else: logger.error("Failed to load dynamic roles from DB on first attempt", exc_info=True) raise diff --git a/tests/src/services/__init__.py b/tests/src/services/__init__.py new file mode 100644 index 00000000..e69de29b diff --git a/tests/src/services/test_role_manager.py b/tests/src/services/test_role_manager.py new file mode 100644 index 00000000..0e121b29 --- /dev/null +++ b/tests/src/services/test_role_manager.py @@ -0,0 +1,32 @@ +import logging +from unittest.mock import patch + +import pytest + +from src.services.role_manager import RoleManager + + +@pytest.fixture(autouse=True) +def enabled_role_manager_logger(monkeypatch): + # The alembic migration tests call logging.config.fileConfig, which disables existing loggers. + monkeypatch.setattr(logging.getLogger("src.services.role_manager"), "disabled", False) + + +class TestLoad: + @pytest.mark.asyncio + async def test_failed_reload_keeps_cache_and_logs_the_cause_without_traceback(self, caplog): + manager = RoleManager() + manager._loaded = True + with ( + patch("src.services.role_manager.AsyncSessionLocal", side_effect=RuntimeError("database is down")), + caplog.at_level(logging.DEBUG, logger="src.services.role_manager"), + ): + await manager.load() + + records = [r for r in caplog.records if r.name == "src.services.role_manager"] + assert len(records) == 1 + assert records[0].levelno == logging.WARNING + assert records[0].getMessage() == ( + "Failed to reload dynamic roles from DB, keeping previous cache: database is down" + ) + assert records[0].exc_info is None diff --git a/tests/src/test_bot.py b/tests/src/test_bot.py index 000a2491..0fe12784 100644 --- a/tests/src/test_bot.py +++ b/tests/src/test_bot.py @@ -62,7 +62,7 @@ async def test_member_not_in_guild_falls_back_to_user_without_traceback(self, ca assert records[0].exc_info is None @pytest.mark.asyncio - async def test_member_and_user_not_found_keeps_traceback(self, caplog): + async def test_member_and_user_not_found_logs_warnings_without_traceback(self, caplog): user_error = NotFound(_response(404), "Unknown User") bot = _bot(NotFound(_response(404), "Unknown Member"), user_result=user_error) with caplog.at_level(logging.DEBUG, logger="src.bot"): @@ -74,10 +74,10 @@ async def test_member_and_user_not_found_keeps_traceback(self, caplog): assert warnings[0].getMessage() == f"Could not find guild member with id: {USER_ID}" assert warnings[0].exc_info is None assert warnings[1].getMessage() == f"Could not find user with id: {USER_ID}" - assert warnings[1].exc_info[1] is user_error + assert warnings[1].exc_info is None @pytest.mark.asyncio - async def test_forbidden_fetching_member_keeps_traceback(self, caplog): + async def test_forbidden_fetching_member_logs_warning_without_traceback(self, caplog): error = Forbidden(_response(403), "Missing Access") bot = _bot(error) with caplog.at_level(logging.DEBUG, logger="src.bot"): @@ -89,10 +89,10 @@ async def test_forbidden_fetching_member_keeps_traceback(self, caplog): assert len(records) == 1 assert records[0].levelno == logging.WARNING assert records[0].getMessage() == f"Unauthorized attempt to fetch member with id: {USER_ID}" - assert records[0].exc_info[1] is error + assert records[0].exc_info is None @pytest.mark.asyncio - async def test_forbidden_fetching_user_after_member_not_found_keeps_traceback(self, caplog): + async def test_forbidden_fetching_user_after_member_not_found_logs_warnings_without_traceback(self, caplog): error = Forbidden(_response(403), "Missing Access") bot = _bot(NotFound(_response(404), "Unknown Member"), user_result=error) with caplog.at_level(logging.DEBUG, logger="src.bot"): @@ -104,7 +104,7 @@ async def test_forbidden_fetching_user_after_member_not_found_keeps_traceback(se assert warnings[0].getMessage() == f"Could not find guild member with id: {USER_ID}" assert warnings[0].exc_info is None assert warnings[1].getMessage() == f"Unauthorized attempt to fetch user with id: {USER_ID}" - assert warnings[1].exc_info[1] is error + assert warnings[1].exc_info is None @pytest.mark.asyncio async def test_http_error_after_member_not_found_logs_error_with_traceback(self, caplog): diff --git a/tests/src/test_logging_rules.py b/tests/src/test_logging_rules.py new file mode 100644 index 00000000..59e18f10 --- /dev/null +++ b/tests/src/test_logging_rules.py @@ -0,0 +1,22 @@ +import ast +from pathlib import Path + +SRC = Path(__file__).resolve().parents[2] / "src" + + +def _warnings_with_traceback() -> list[str]: + found = [] + for path in sorted(SRC.rglob("*.py")): + for node in ast.walk(ast.parse(path.read_text())): + if ( + isinstance(node, ast.Call) + and isinstance(node.func, ast.Attribute) + and node.func.attr == "warning" + and any(kw.arg in ("exc_info", "stack_info") for kw in node.keywords) + ): + found.append(f"{path.relative_to(SRC.parent)}:{node.lineno}") + return found + + +def test_warnings_do_not_log_a_traceback(): + assert _warnings_with_traceback() == [] From 7e7260423117e204ac7269c4592f8a53ec76cd62 Mon Sep 17 00:00:00 2001 From: Dimosthenis Schizas Date: Tue, 6 Oct 2026 12:17:57 +0300 Subject: [PATCH 4/4] fix(logging): keep the cause in HTTPException warnings, align user lookup wording The ban, ban DM and infraction DM warnings now end with the Discord error (status, reason and error code), so the cause is logged without a traceback. The ban DM warning also said unban; it now says what failed. The user fallback after an HTTPException on the member lookup now uses the same messages as the fallback after NotFound. --- src/bot.py | 6 ++-- src/helpers/ban.py | 12 +++---- tests/src/helpers/test_ban.py | 64 ++++++++++++++++++++++++++++++++++- tests/src/test_bot.py | 23 +++++++++++++ 4 files changed, 95 insertions(+), 10 deletions(-) diff --git a/src/bot.py b/src/bot.py index bfa97cfd..efe72d6a 100644 --- a/src/bot.py +++ b/src/bot.py @@ -223,12 +223,12 @@ async def get_member_or_user(self, guild: Guild, id_: int) -> Member | User | No try: return await self.get_or_fetch_user(id_) except Forbidden: - logger.warning(f"Unauthorized attempt to fetch member with id: {id_}") + logger.warning(f"Unauthorized attempt to fetch user with id: {id_}") except NotFound: - logger.warning(f"Could not find guild member with id: {id_}") + logger.warning(f"Could not find user with id: {id_}") except HTTPException as exc: logger.error( - f"Discord error while fetching guild member with id: {id_}", + f"Discord error while fetching user with id: {id_}", exc_info=exc, ) diff --git a/src/helpers/ban.py b/src/helpers/ban.py index 1da5b9eb..bb46c0b0 100644 --- a/src/helpers/ban.py +++ b/src/helpers/ban.py @@ -357,8 +357,8 @@ async def ban_member_with_epoch( code=BanCodes.FAILED, ) return - except HTTPException: - logger.warning(f"HTTPException when trying to ban user with ID {member.id}") + except HTTPException as exc: + logger.warning(f"HTTPException when trying to ban user with ID {member.id}: {exc}") if author: return SimpleResponse( message="Here's a 400 Bad Request for you. Just like when you tried to ask me out, last week.", @@ -466,8 +466,8 @@ async def _dm_banned_member( f"Could not DM member with id {member.id} due to privacy settings, however will still attempt to ban " f"them..." ) - except HTTPException: - logger.warning(f"HTTPException when trying to unban user with ID {member.id}") + except HTTPException as exc: + logger.warning(f"HTTPException when trying to DM user with ID {member.id} about their ban: {exc}") return False @@ -604,8 +604,8 @@ async def add_infraction( except Forbidden: message = "Could not DM member due to privacy settings, however the infraction was still added." logger.warning(f"Forbidden, when trying to contact user with ID {member.id} about infraction.") - except HTTPException: + except HTTPException as exc: message = "Here's a 400 Bad Request for you. Just like when you tried to ask me out, last week." - logger.warning(f"HTTPException when trying to add infraction for user with ID {member.id}") + logger.warning(f"HTTPException when trying to add infraction for user with ID {member.id}: {exc}") return SimpleResponse(message=message, delete_after=None) diff --git a/tests/src/helpers/test_ban.py b/tests/src/helpers/test_ban.py index c8eae476..8e79c6ab 100644 --- a/tests/src/helpers/test_ban.py +++ b/tests/src/helpers/test_ban.py @@ -1,3 +1,4 @@ +import logging from datetime import datetime, timezone from unittest import mock from unittest.mock import AsyncMock, MagicMock, patch @@ -5,7 +6,7 @@ import pytest from discord import Forbidden, HTTPException -from src.helpers.ban import EVIDENCE_REQUIRED_MESSAGE, _check_member, _dm_banned_member, ban_member +from src.helpers.ban import EVIDENCE_REQUIRED_MESSAGE, _check_member, _dm_banned_member, add_infraction, ban_member from src.helpers.responses import SimpleResponse from tests import helpers @@ -277,3 +278,64 @@ async def test_ban_self(self, ctx, bot, guild): assert isinstance(response, SimpleResponse) assert response.message == "You cannot ban yourself." + + +def _http_exception() -> HTTPException: + response = MagicMock(status=500, reason="Internal Server Error") + return HTTPException(response, {"code": 0, "message": "Something broke"}) + + +HTTP_EXCEPTION_TEXT = "500 Internal Server Error (error code: 0): Something broke" + + +@pytest.fixture +def ban_logs(caplog, monkeypatch): + # The alembic migration tests call logging.config.fileConfig, which disables existing loggers. + monkeypatch.setattr(logging.getLogger("src.helpers.ban"), "disabled", False) + caplog.set_level(logging.DEBUG, logger="src.helpers.ban") + + def warnings() -> list[logging.LogRecord]: + return [r for r in caplog.records if r.name == "src.helpers.ban" and r.levelno == logging.WARNING] + + return warnings + + +class TestHttpExceptionWarnings: + @pytest.mark.asyncio + async def test_failed_ban_logs_the_cause(self, bot, guild, member, ban_logs): + future_timestamp = int(datetime.now(tz=timezone.utc).timestamp() + 86400) + guild.ban = AsyncMock(side_effect=_http_exception()) + with ( + mock.patch("src.helpers.ban._check_member", return_value=None), + mock.patch("src.helpers.ban._dm_banned_member", return_value=True), + mock.patch("src.helpers.ban._get_ban_or_create", return_value=(1, False)), + mock.patch("src.helpers.ban.validate_duration", return_value=(future_timestamp, "")), + ): + await ban_member(bot, guild, member, "1d", "reason", "evidence") + + assert [r.getMessage() for r in ban_logs()] == [ + f"HTTPException when trying to ban user with ID {member.id}: {HTTP_EXCEPTION_TEXT}" + ] + assert ban_logs()[0].exc_info is None + + @pytest.mark.asyncio + async def test_failed_ban_dm_logs_the_cause(self, guild, member, ban_logs): + member.send = AsyncMock(side_effect=_http_exception()) + result = await _dm_banned_member("2023-05-19", guild, member, "reason") + + assert result is False + assert [r.getMessage() for r in ban_logs()] == [ + f"HTTPException when trying to DM user with ID {member.id} about their ban: {HTTP_EXCEPTION_TEXT}" + ] + assert ban_logs()[0].exc_info is None + + @pytest.mark.asyncio + async def test_failed_infraction_dm_logs_the_cause(self, guild, member, ban_logs): + member.send = AsyncMock(side_effect=_http_exception()) + with mock.patch("src.helpers.ban.AsyncSessionLocal"): + await add_infraction(guild, member, 1, "reason", helpers.MockMember()) + + assert [r.getMessage() for r in ban_logs()] == [ + f"HTTPException when trying to add infraction for user with ID {member.id}: {HTTP_EXCEPTION_TEXT}" + ] + assert ban_logs()[0].exc_info is None diff --git a/tests/src/test_bot.py b/tests/src/test_bot.py index 0fe12784..9eceb59d 100644 --- a/tests/src/test_bot.py +++ b/tests/src/test_bot.py @@ -132,3 +132,26 @@ async def test_http_error_fetching_member_falls_back_to_user(self, caplog): assert records[0].levelno == logging.ERROR assert records[0].getMessage() == f"Discord error while fetching guild member with id: {USER_ID}" assert records[0].exc_info[1] is error + + @pytest.mark.asyncio + @pytest.mark.parametrize( + ("user_error", "level", "message"), + [ + (Forbidden(_response(403), "Missing Access"), logging.WARNING, + f"Unauthorized attempt to fetch user with id: {USER_ID}"), + (NotFound(_response(404), "Unknown User"), logging.WARNING, + f"Could not find user with id: {USER_ID}"), + (HTTPException(_response(500), "boom"), logging.ERROR, + f"Discord error while fetching user with id: {USER_ID}"), + ], + ) + async def test_user_fallback_after_http_error_logs_user_wording(self, caplog, user_error, level, message): + bot = _bot(HTTPException(_response(500), "boom"), user_result=user_error) + with caplog.at_level(logging.DEBUG, logger="src.bot"): + result = await Bot.get_member_or_user(bot, bot.guild, USER_ID) + + assert result is None + records = _records(caplog) + assert len(records) == 2 + assert records[1].levelno == level + assert records[1].getMessage() == message