clubesportsudes/team-tryouts
0
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

fix(bot): une reaction qui echoue le dit, au lieu de se taire

Browse Source 
Chaque gestionnaire de discord_bot.py enveloppait tout son corps dans un
except Exception qui journalisait et poursuivait. Un refus de la base, une
boite de reception fermee et une faute de frappe dans ce module produisaient
la meme ligne, et la personne qui avait clique n'apprenait rien dans aucun
des trois cas.

Le defaut que l'audit citait en exemple : dans handle_attendance_confirm, le
commit et le message "Your attendance has been confirmed!" etaient dans le
meme bloc protege. Si le commit levait, rien n'etait envoye et rien n'etait
signale. La reaction devenait indiscernable d'un bot arrete.

Trois familles, trois reponses. La base refuse : rollback, l'entree pending
est conservee pour que la reaction reste reessayable, et la personne est
prevenue que rien n'a ete enregistre. Discord est injoignable : apres un
commit c'est du meilleur effort, un DM qui rebondit ne defait pas une
decision prise. Tout le reste est un defaut et remonte, jusqu'a on_error,
qui est ajoute parce que discord.py journalise sur le logger 'discord' que
configure_logging ne collecte pas.

Trouve en appliquant : deux reactions sur le meme message passent toutes
deux le test d'appartenance puis s'attendent sur deux await, et la perdante
levait un KeyError qui se lisait comme une erreur sans consequence ; un
fetch_channel en echec renvoyait sans un mot, donc un clic sans effet et
sans trace ; un start_scheduler en echec supprime tous les rappels a jamais
et laissait trois cles de /health au vert, d'ou reminders_scheduled.

L'ordre des etapes apres le commit est desormais fixe : oublier l'entree
pending avant les messages, sinon un DM rebondi laisse une demande deja
approuvee reactivable une seconde fois.

Les tests ont ete verifies par mutation du code de production. La deuxieme
mutation a trouve une faiblesse dans le test lui-meme, qui ne regardait que
le premier message emis.

QUA-004 (roadmap) / ARCH-008 (constats).

Co-Authored-By: Claude Opus 5 <[email protected]>
This commit is contained in:
GGThed
2026-08-11 16:28:58 -04:00
co-authored by Claude Opus 5
parent 7a1dab21cd
commit 546f28571b
3 changed files with 1013 additions and 294 deletions
Download Patch File Download Diff File Expand all files Collapse all files
app/discord_bot.py
+400 -125
View File
@@ -4,6 +4,40 @@ This module provides a persistent bot that handles:
- One on One request approvals/rejections via reactions
- Match/tryout schedule addition notifications with attendance confirmation
- Daily reminders at 18:00 EDT for upcoming events
Three families of failure, and what each one does (ARCH-008 / QUA-004)
----------------------------------------------------------------------
Every handler in this file used to wrap its whole body in one
`try/except Exception` that logged and carried on. A database refusal, a
closed inbox and a typo in this module all produced the same line, and the
person who clicked the reaction was told nothing either way. The handlers
now separate three cases, because they need three different answers:
1. **The database refused the write** — `SQLAlchemyError`. The session is
rolled back, the pending entry is kept so the same reaction can be tried
again, and the person is told that nothing was recorded. Silence here was
the worst of the three: a confirmation that failed to commit looked
exactly like a bot that was not running.
2. **Discord could not be reached** — `HTTPException` and its subclasses
(`Forbidden`, `NotFound`). Expected, per recipient, and already named one
by one in `_send_dm`. After a commit these are best-effort: the decision
is recorded whether or not the message got through, and undoing it
because a DM bounced would be worse than the bounce.
3. **Anything else is a defect** — it propagates. `on_error` records it with
its traceback, under this application's logger rather than discord.py's.
A defect that reads like a delivery failure never gets fixed.
Four catches are still broad, and all four are boundaries with nothing above
them to catch anything: the queue loop, the APScheduler job, the thread the
bot runs in, and the hand-off from a Flask request. Each says on its line why.
Ruff's `BLE` rule is enabled (QUA-004), and what it enforces is not "never
catch broadly" — it is satisfied by logging the traceback. Which is the
whole discipline: a boundary may swallow anything, provided it leaves behind
enough to tell a defect from an outage.
"""
import asyncio
@@ -13,7 +47,6 @@ import os
import tempfile
import threading
import time
import traceback
from datetime import datetime, timedelta
from queue import Empty, Queue
from zoneinfo import ZoneInfo
@@ -23,6 +56,7 @@ from apscheduler.triggers.cron import CronTrigger
from discord import Forbidden, HTTPException, Intents, NotFound
from discord.ext import commands
from dotenv import load_dotenv
from sqlalchemy.exc import SQLAlchemyError
load_dotenv()
DISCORD_BOT_TOKEN = os.getenv('DISCORD_BOT_TOKEN')
@@ -93,6 +127,10 @@ class TeamTryoutsBot(commands.Bot):
self.scheduler = AsyncIOScheduler()
self.timezone = ZoneInfo('America/Toronto') # EDT timezone
self._user_cache = {} # Discord snowflake -> User, bounded (PERF-005)
#: Whether the 18:00 reminder job is actually scheduled. Starts False
#: and is only set by start_scheduler succeeding, so /health reports
#: 'not yet' rather than guessing (ARCH-008).
self.reminders_scheduled = False
def _load_pending(self):
"""Load pending requests from the JSON file.
@@ -194,12 +232,33 @@ class TeamTryoutsBot(commands.Bot):
self._load_pending()
logger.info(f'TeamTryoutsBot logged in as {self.user}')
async def on_error(self, event_method, *args, **kwargs):
"""Record an exception that escaped an event handler.
This is the third family: not a database refusal, not Discord being
unreachable — a defect. discord.py's own handler logs it on the
`discord` logger, which `configure_logging` does not wire to any of
this application's files: it attaches handlers to the `app` package
(logging_config.py). So an unexpected failure inside a reaction
handler went to a logger nobody reads, and the reaction looked
ignored.
Deliberately says nothing to the user. At this point what did and did
not happen is exactly what is unknown, and a reassuring message would
be a guess.
"""
logger.exception(
'Unhandled exception in %s. This is a defect, not a delivery failure: '
'expected Discord and database errors are handled where they occur.',
event_method,
)
async def on_ready(self):
"""Log when the bot is ready and start background tasks."""
try:
guilds = [g.name for g in self.guilds]
logger.info(f'TeamTryoutsBot is ready! Logged in as {self.user} | Guilds: {guilds}')
except Exception:
except AttributeError:
logger.info(f'TeamTryoutsBot is ready! Logged in as {self.user}')
# Start the queue processing task
@@ -219,6 +278,12 @@ class TeamTryoutsBot(commands.Bot):
The grace period is deliberately short of the next occurrence: a
reminder for tonight is worth sending an hour late, not tomorrow.
A failure here is permanent and total — no reminder is ever sent
again — and used to leave one line in a log. It is now visible from
outside, in /health, because that is the difference between finding
out at start-up and finding out when a player asks why the reminders
stopped (ARCH-008).
"""
try:
self.scheduler.add_job(
@@ -231,9 +296,67 @@ class TeamTryoutsBot(commands.Bot):
max_instances=1,
)
self.scheduler.start()
except Exception: # a scheduler that will not start must not take on_ready with it
self.reminders_scheduled = False
logger.exception(
'Daily reminder scheduler could not be started. No reminder will be '
'sent until the process is restarted; /health reports this.'
)
return
self.reminders_scheduled = True
logger.info('Daily reminder scheduler started (18:00 EDT)')
except Exception as e:
logger.error(f'Error starting scheduler: {e}')
async def _reply(self, channel, message):
"""Answer the person who reacted, and never let that answer be fatal.
Returns True when it went out. A reply is the only feedback a
reaction gets, so a failed one is worth a line — but it must not undo
a state change that has already been committed.
"""
try:
await channel.send(message)
except HTTPException as exc:
logger.error('Could not answer a reaction on Discord: %s', exc)
return False
return True
async def _commit_or_report(self, channel, *, operation):
"""Make the pending change durable, or say plainly that it is not.
Returns True when the write landed. On a database refusal the session
is rolled back, the pending entry is left in place so the same
reaction can be tried again, and the person is told that nothing was
recorded — previously the failure was logged and the coroutine
returned, which is indistinguishable from the bot being down.
Anything that is not a database error propagates: it is a defect, and
on_error records it as one.
"""
from app.extensions import db
try:
db.session.commit()
except SQLAlchemyError:
db.session.rollback()
logger.exception('%s was not recorded: the database refused the write', operation)
await self._reply(
channel,
"⚠️ Nothing was recorded — the database refused the change. "
"Please answer from the web interface instead.",
)
return False
return True
def _forget_pending(self, message_id):
"""Drop a message from the pending map, once its answer is durable.
`pop` rather than `del`: two reactions on the same message race
through two coroutines, and the loser raised KeyError inside the old
blanket handler, where it read as an error with no consequence.
"""
if self.pending_requests.pop(message_id, None) is not None:
self._save_pending()
async def _resolve_user(self, discord_uid, *, context=''):
"""Return the Discord user behind a snowflake, or None.
@@ -317,29 +440,46 @@ class TeamTryoutsBot(commands.Bot):
logger.info('Delivered %s to %s (message_id=%s)', purpose, who, sent.id)
return sent
async def _dispatch(self, item):
"""Send one queued notification, inside an app context where needed."""
kind = item.get('type')
if kind == 'one_on_one_request':
await self._send_one_on_one_dm(**item['data'])
elif kind == 'schedule_addition':
if self.flask_app:
with self.flask_app.app_context():
await self._send_schedule_notification(**item['data'])
else:
await self._send_schedule_notification(**item['data'])
elif kind == 'one_on_one_response':
await self._send_one_on_one_response_dm(**item['data'])
else:
logger.error('Unknown queue item type %r; the notification was dropped', kind)
async def process_queue(self):
"""Process messages from the queue (runs continuously)."""
"""Drain the queue fed by the Flask threads, for the life of the bot.
The loop is the last thing standing between one bad item and every
subsequent notification, so it catches everything. What reaches it is
narrower than it used to be: `_send_dm` already reports a closed inbox
or an outage per recipient and returns None, so anything arriving here
got past the typed handling and is a defect. It reads as one.
"""
while True:
try:
try:
item = self.message_queue.get_nowait()
except Empty:
await asyncio.sleep(0.5)
continue
if item.get('type') == 'one_on_one_request':
await self._send_one_on_one_dm(**item['data'])
elif item.get('type') == 'schedule_addition':
if self.flask_app:
with self.flask_app.app_context():
await self._send_schedule_notification(**item['data'])
else:
await self._send_schedule_notification(**item['data'])
elif item.get('type') == 'one_on_one_response':
await self._send_one_on_one_response_dm(**item['data'])
except Exception as e:
logger.error(f"Error processing queue: {e}\n{traceback.format_exc()}")
try:
await self._dispatch(item)
except Exception: # the loop must outlive a single bad item
logger.exception(
'Unexpected failure while sending a %r notification. It is lost; '
'delivery failures that are merely expected do not reach here.',
item.get('type'),
)
await asyncio.sleep(0.1)
def is_dm_channel(self, channel) -> bool:
@@ -359,7 +499,16 @@ class TeamTryoutsBot(commands.Bot):
# Fetch the channel and check if it's a DM
try:
channel = await self.fetch_channel(payload.channel_id)
except Exception:
except HTTPException as exc:
# Silent before. The reaction is now unanswerable — there is no
# channel to answer in — so the log line is the only trace there
# will ever be that someone clicked and nothing happened.
logger.warning(
'Could not open the channel of a reaction on message %s: %s. '
'The reaction was not acted on.',
payload.message_id,
exc,
)
return
if not self.is_dm_channel(channel):
@@ -555,17 +704,33 @@ class TeamTryoutsBot(commands.Bot):
return msg.id
async def handle_one_on_one_approve(self, coach, message_id, request_id, channel):
"""Handle coach approving a One on One request."""
try:
"""Record a coach's approval, then tell the coach and the player.
Four steps, and they do not fail alike: read the request and stage
the change (database), commit it (database, and the only step whose
failure means nothing happened), answer the coach (Discord), tell the
player (Discord). Everything after the commit is best-effort by
definition — the decision is recorded, and a DM that bounces does not
un-record it.
"""
from app.extensions import db
from app.models import OneOnOneRequest
try:
request = OneOnOneRequest.query.get(request_id)
if not request:
# The row is gone; no reaction on this message can ever mean
# anything again. Keeping the mapping is what PENDING_MAX_AGE_DAYS
# was invented to bound.
logger.info(
'One on One request %s no longer exists; its pending message was dropped.',
request_id,
)
self._forget_pending(message_id)
return
if request.coach.discord_user_id != str(coach.id):
await channel.send("⚠️ You are not the intended recipient.")
await self._reply(channel, "⚠️ You are not the intended recipient.")
return
# Re-attach to current session (object may be detached across app contexts)
@@ -578,13 +743,30 @@ class TeamTryoutsBot(commands.Bot):
request.status = 'approved'
request.responded_at = datetime.utcnow()
db.session.commit()
except SQLAlchemyError:
db.session.rollback()
logger.exception('Could not read One on One request %s to approve it', request_id)
await self._reply(
channel,
"⚠️ Nothing was recorded — the request could not be read. "
"Please answer from the web interface instead.",
)
return
await channel.send(
f"✅ You have **approved** the One on One session with {player_full_name}."
if not await self._commit_or_report(
channel, operation=f'Approval of One on One request {request_id}'
):
return
# Durable from here. Order matters: forget the pending entry before
# the two messages, so that a bounced DM cannot leave a request that
# is already approved answerable a second time.
self._forget_pending(message_id)
await self._reply(
channel, f"✅ You have **approved** the One on One session with {player_full_name}."
)
# Notify player via Discord
if player_discord_id:
await self.notify_player_about_one_on_one_direct(
player_discord_id=player_discord_id,
@@ -593,24 +775,30 @@ class TeamTryoutsBot(commands.Bot):
request=request,
approved=True,
)
del self.pending_requests[message_id]
self._save_pending()
except Exception as e:
logger.error(f"Error handling approval: {e}\n{traceback.format_exc()}")
async def handle_one_on_one_reject(self, coach, message_id, request_id, channel):
"""Handle coach rejecting a One on One request."""
try:
"""Record a coach's refusal, with the reason they replied, if any.
Same four steps as the approval, plus a fifth that fails on its own
terms: reading back the coach's reply to find a refusal note. That
one is optional by construction — a refusal without a note is a
refusal — so it is caught where it happens and the rest continues.
"""
from app.extensions import db
from app.models import OneOnOneRequest
try:
request = OneOnOneRequest.query.get(request_id)
if not request:
logger.info(
'One on One request %s no longer exists; its pending message was dropped.',
request_id,
)
self._forget_pending(message_id)
return
if request.coach.discord_user_id != str(coach.id):
await channel.send("⚠️ You are not the intended recipient.")
await self._reply(channel, "⚠️ You are not the intended recipient.")
return
# Re-attach to current session (object may be detached across app contexts)
@@ -619,6 +807,15 @@ class TeamTryoutsBot(commands.Bot):
player_full_name = request.player.full_name if request.player else 'Unknown'
player_discord_id = request.player.discord_user_id if request.player else None
coach_obj = request.coach
except SQLAlchemyError:
db.session.rollback()
logger.exception('Could not read One on One request %s to reject it', request_id)
await self._reply(
channel,
"⚠️ Nothing was recorded — the request could not be read. "
"Please answer from the web interface instead.",
)
return
refusal_note = None
try:
@@ -630,24 +827,39 @@ class TeamTryoutsBot(commands.Bot):
):
refusal_note = reply.content
break
except Exception as e:
logger.warning(f"Could not check for reply message: {e}")
except HTTPException as exc:
logger.warning(
'Could not read the channel history for a refusal note on request %s: %s. '
'The refusal is still recorded, without a reason.',
request_id,
exc,
)
try:
request.status = 'rejected'
request.responded_at = datetime.utcnow()
if refusal_note:
request.coach_rejection_message = refusal_note
db.session.commit()
except SQLAlchemyError:
db.session.rollback()
logger.exception('Could not stage the refusal of One on One request %s', request_id)
await self._reply(channel, "⚠️ Nothing was recorded. Please use the web interface.")
return
rejection_msg = (
f"❌ You have **rejected** the One on One session with {player_full_name}."
)
if not await self._commit_or_report(
channel, operation=f'Refusal of One on One request {request_id}'
):
return
self._forget_pending(message_id)
rejection_msg = f"❌ You have **rejected** the One on One session with {player_full_name}."
if refusal_note:
rejection_msg += f"\n**Reason:** {refusal_note}"
else:
rejection_msg += "\n\nℹ️ The player has been notified that you are not available."
await channel.send(rejection_msg)
await self._reply(channel, rejection_msg)
if player_discord_id:
await self.notify_player_about_one_on_one_direct(
player_discord_id=player_discord_id,
@@ -657,11 +869,6 @@ class TeamTryoutsBot(commands.Bot):
approved=False,
refusal_note=refusal_note,
)
del self.pending_requests[message_id]
self._save_pending()
except Exception as e:
logger.error(f"Error handling rejection: {e}\n{traceback.format_exc()}")
@staticmethod
def _attendance_record(event_type, reference_id):
@@ -701,16 +908,29 @@ class TeamTryoutsBot(commands.Bot):
return bool(owner and owner.discord_user_id == str(reacting_user.id))
async def handle_attendance_confirm(self, player, message_id, reference_id, channel):
"""Handle player confirming attendance for a match/tryout."""
try:
"""Record a player confirming attendance for a match or tryout.
This is the handler the audit used to describe ARCH-008. The player
was told "✅ Your attendance has been confirmed!" from inside the same
blanket handler that swallowed the commit — so a database refusal
produced no message at all, and the reaction was indistinguishable
from a bot that had stopped running. The commit and the message are
now separate steps with separate outcomes.
"""
from app.extensions import db
request_info = self.pending_requests[message_id]
request_info = self.pending_requests.get(message_id)
if request_info is None:
# Two awaits happened since on_raw_reaction_add checked; the
# other reaction on the same message got here first.
return
event_type = request_info.get('event_type')
try:
row, player_id = self._attendance_record(event_type, reference_id)
if row is not None and not self._reacting_user_owns(player_id, player):
await channel.send("⚠️ You are not the intended recipient.")
await self._reply(channel, "⚠️ You are not the intended recipient.")
return
if row is not None:
@@ -730,27 +950,46 @@ class TeamTryoutsBot(commands.Bot):
player.id,
reference_id,
)
except SQLAlchemyError:
db.session.rollback()
logger.exception(
'Could not read the %s participation row %s to confirm attendance',
event_type,
reference_id,
)
await self._reply(
channel,
"⚠️ Nothing was recorded. Please confirm from the web interface instead.",
)
return
db.session.commit()
if not await self._commit_or_report(
channel, operation=f'Attendance confirmation for {event_type} row {reference_id}'
):
return
await channel.send("✅ Your attendance has been confirmed!")
del self.pending_requests[message_id]
self._save_pending()
except Exception as e:
logger.error(f"Error handling attendance confirmation: {e}\n{traceback.format_exc()}")
self._forget_pending(message_id)
await self._reply(channel, "✅ Your attendance has been confirmed!")
async def handle_attendance_decline(self, player, message_id, reference_id, channel):
"""Handle player declining attendance for a match/tryout."""
try:
"""Record a player declining attendance for a match or tryout.
The mirror of handle_attendance_confirm, and the same reasoning: a
declined match deletes a participation row, which is exactly the kind
of write a foreign key can refuse. The player now hears about it.
"""
from app.extensions import db
request_info = self.pending_requests[message_id]
request_info = self.pending_requests.get(message_id)
if request_info is None:
return
event_type = request_info.get('event_type')
try:
row, player_id = self._attendance_record(event_type, reference_id)
if row is not None and not self._reacting_user_owns(player_id, player):
await channel.send("⚠️ You are not the intended recipient.")
await self._reply(channel, "⚠️ You are not the intended recipient.")
return
if row is not None:
@@ -759,15 +998,26 @@ class TeamTryoutsBot(commands.Bot):
db.session.delete(row)
else:
row.status = 'no_show'
except SQLAlchemyError:
db.session.rollback()
logger.exception(
'Could not read the %s participation row %s to decline attendance',
event_type,
reference_id,
)
await self._reply(
channel,
"⚠️ Nothing was recorded. Please answer from the web interface instead.",
)
return
db.session.commit()
if not await self._commit_or_report(
channel, operation=f'Attendance refusal for {event_type} row {reference_id}'
):
return
await channel.send("❌ Your attendance has been declined.")
del self.pending_requests[message_id]
self._save_pending()
except Exception as e:
logger.error(f"Error handling attendance decline: {e}\n{traceback.format_exc()}")
self._forget_pending(message_id)
await self._reply(channel, "❌ Your attendance has been declined.")
async def notify_player_about_one_on_one_direct(
self,
@@ -790,10 +1040,15 @@ class TeamTryoutsBot(commands.Bot):
request: The OneOnOneRequest object (for date/time/points data only).
approved: Whether the session was approved.
refusal_note: Optional coach refusal reason.
Catches nothing of its own. Every caller reaches this after the
coach's answer is committed, so a failure here costs the player a
message and nothing else — and if it is a defect (a request whose
date is None, say) it must be seen as one, in on_error, rather than
flattened into "Error in direct One on One notification".
"""
try:
if not player_discord_id:
logger.warning(f"Player has no Discord user ID for request {request.id}")
logger.warning('Player has no Discord user ID for request %s', request.id)
return
if approved:
@@ -805,8 +1060,7 @@ class TeamTryoutsBot(commands.Bot):
f"**Discussion Points:** {request.points or 'No specific points provided'}\n\n"
"Please prepare for your session!"
)
else:
if refusal_note:
elif refusal_note:
message = (
"😞 **One on One Session Rejected**\n\n"
f"Your coach **{coach_full_name}** has declined:\n"
@@ -827,23 +1081,32 @@ class TeamTryoutsBot(commands.Bot):
recipient=player_full_name,
)
except Exception as e:
logger.error(f"Error in direct One on One notification: {e}")
async def send_daily_reminders(self):
"""Send daily reminders at 18:00 EDT for events in 24-48 hours."""
"""Run the 18:00 batch. The APScheduler job boundary.
Broad on purpose: nothing above this is ours. An exception escaping
an APScheduler job is logged by the library and the job stays
scheduled, but the line it writes says nothing about what this batch
was doing, and it lands on a logger this application does not
collect.
"""
try:
if self.flask_app:
with self.flask_app.app_context():
await self._send_daily_reminders_impl()
else:
await self._send_daily_reminders_impl()
except Exception as e:
logger.error(f"Error sending daily reminders: {e}\n{traceback.format_exc()}")
except Exception: # a failed batch must not unschedule tomorrow's
logger.exception('The daily reminder batch failed. Tomorrow’s run is unaffected.')
async def _send_daily_reminders_impl(self):
"""Internal implementation of daily reminders with proper app context."""
try:
"""Internal implementation of daily reminders with proper app context.
Only the database is caught here. A batch that cannot read the
schedule has nothing to send and is worth one clear line; a batch
that fails for any other reason is a defect and belongs in the
traceback that send_daily_reminders writes.
"""
from sqlalchemy.orm import joinedload
from app.models import (
@@ -863,6 +1126,7 @@ class TeamTryoutsBot(commands.Bot):
# they all went out (PERF-005).
attempted = delivered = 0
try:
# Find matches for tomorrow
matches = Match.query.filter(Match.date == tomorrow).all()
for match in matches:
@@ -893,6 +1157,14 @@ class TeamTryoutsBot(commands.Bot):
if session.player and session.player.discord_user_id:
attempted += 1
delivered += await self.send_one_on_one_reminder(session.player, session)
except SQLAlchemyError:
db_reached = f'{delivered} of {attempted} sent before it stopped'
logger.exception(
'The daily reminder batch for %s could not read the schedule (%s)',
tomorrow,
db_reached,
)
return
if attempted and delivered < attempted:
logger.warning(
@@ -906,9 +1178,6 @@ class TeamTryoutsBot(commands.Bot):
else:
logger.info('Daily reminders for %s: %d delivered', tomorrow, delivered)
except Exception as e:
logger.error(f"Error sending daily reminders: {e}")
async def send_match_reminder(self, player, match):
"""Send match reminder to player. True if it was delivered."""
message = (
@@ -960,8 +1229,12 @@ class TeamTryoutsBot(commands.Bot):
"""Send a DM to a player notifying them of their One on One request response.
Called from the message queue when a coach accepts/rejects via the web app.
Every argument is a string prepared by the caller, and _send_dm
already handles a closed inbox and an outage. There is nothing left
for a blanket catch to protect against, so anything that goes wrong
here is a defect and process_queue records it as one.
"""
try:
if not player_discord_id:
logger.warning("Cannot send response DM: no player_discord_id")
return False
@@ -975,8 +1248,7 @@ class TeamTryoutsBot(commands.Bot):
f"**Discussion Points:** {points or 'No specific points provided'}\n\n"
"Please prepare for your session!"
)
else:
if refusal_note:
elif refusal_note:
message = (
"😞 **One on One Session Rejected**\n\n"
f"Your coach **{coach_full_name}** has declined:\n"
@@ -998,10 +1270,6 @@ class TeamTryoutsBot(commands.Bot):
)
return sent is not None
except Exception as e:
logger.error(f"Error sending One on One response DM: {e}")
return False
async def send_one_on_one_reminder(self, player, session):
"""Send One on One reminder to player. True if it was delivered."""
message = (
@@ -1036,6 +1304,28 @@ def get_bot(flask_app=None):
return bot_instance
def _enqueue(kind: str, data: dict, *, description: str) -> bool:
"""Hand one notification to the bot thread. Never raises.
The three public senders below were the same fifteen lines three times,
each with its own blanket catch. There is one now, and it is the only
place in this module where breadth is a property of the caller rather
than of the failure: this runs in a Flask request thread, and the work
the notification announces is already committed. The meeting is booked
whether or not Discord hears about it, so a failure here must not become
a 500 on a page whose job is done.
What it is not is somewhere to lose a defect: the traceback is logged
and the caller is told False.
"""
try:
get_bot().message_queue.put({'type': kind, 'data': data})
except Exception: # a notification must never fail the request that caused it
logger.exception('Could not queue %s', description)
return False
return True
def send_one_on_one_dm(
coach_name: str,
coach_discord_id: str,
@@ -1048,12 +1338,9 @@ def send_one_on_one_dm(
request_id: int,
) -> bool:
"""Queue a One on One request DM to be sent by the bot."""
bot = get_bot()
try:
bot.message_queue.put(
return _enqueue(
'one_on_one_request',
{
'type': 'one_on_one_request',
'data': {
'coach_name': coach_name,
'coach_discord_id': coach_discord_id,
'player_name': player_name,
@@ -1064,12 +1351,8 @@ def send_one_on_one_dm(
'points': points,
'request_id': request_id,
},
}
description=f'the One on One request DM for request {request_id}',
)
return True
except Exception as e:
logger.error(f"Error queuing One on One DM: {e}")
return False
def send_schedule_notification(
@@ -1081,12 +1364,9 @@ def send_schedule_notification(
reference_id: int,
) -> bool:
"""Queue a schedule addition notification to be sent by the bot."""
bot = get_bot()
try:
bot.message_queue.put(
return _enqueue(
'schedule_addition',
{
'type': 'schedule_addition',
'data': {
'user_id': user_id,
'event_type': event_type,
'event_title': event_title,
@@ -1094,12 +1374,8 @@ def send_schedule_notification(
'event_time': event_time,
'reference_id': reference_id,
},
}
description=f'the {event_type} notification for user {user_id}',
)
return True
except Exception as e:
logger.error(f"Error queuing schedule notification: {e}")
return False
def send_one_on_one_response(
@@ -1117,12 +1393,9 @@ def send_one_on_one_response(
Called from Flask routes when a coach accepts/rejects via the web app.
"""
bot = get_bot()
try:
bot.message_queue.put(
return _enqueue(
'one_on_one_response',
{
'type': 'one_on_one_response',
'data': {
'player_discord_id': player_discord_id,
'player_full_name': player_full_name,
'coach_full_name': coach_full_name,
@@ -1133,12 +1406,8 @@ def send_one_on_one_response(
'approved': approved,
'refusal_note': refusal_note,
},
}
description=f'the One on One response DM for {player_full_name}',
)
return True
except Exception as e:
logger.error(f"Error queuing One on One response DM: {e}")
return False
def start_bot(flask_app=None):
@@ -1151,8 +1420,8 @@ def start_bot(flask_app=None):
def run_bot():
try:
bot.run(DISCORD_BOT_TOKEN)
except Exception as e:
logger.error(f"Bot error: {e}")
except Exception: # top of a thread; there is nothing above to catch it
logger.exception('The Discord bot thread stopped on an unhandled error')
finally:
# bot.run() returning means the connection is gone for good:
# discord.py reconnects on its own for anything recoverable.
@@ -1176,10 +1445,15 @@ def bot_status():
Nothing reported it, so nobody found out until someone asked why they
had stopped receiving reminders.
`reminders_scheduled` is the second silent-death case (ARCH-008): the
thread can be alive and the gateway connected while the 18:00 job never
got scheduled, in which case nothing is ever sent at 18:00 and the other
three keys all read green.
Returns:
dict: `configured` (a token is set), `running` (the thread is
alive), `connected` (the gateway session is up) and `pending`
(reaction mappings held in memory).
alive), `connected` (the gateway session is up), `pending`
(reaction mappings held in memory) and `reminders_scheduled`.
"""
running = bool(bot_thread and bot_thread.is_alive())
instance = bot_instance
@@ -1189,4 +1463,5 @@ def bot_status():
'running': running,
'connected': connected,
'pending': len(instance.pending_requests) if instance else 0,
'reminders_scheduled': bool(instance and instance.reminders_scheduled),
}
tests/test_bot_error_families.py
+430
View File
@@ -0,0 +1,430 @@
"""Three families of failure, and the three different answers they get.
ARCH-008 / QUA-004. Every handler in `discord_bot.py` used to wrap its
whole body in one `except Exception` that logged a line and returned, so
these three all looked the same from the outside and two of them looked the
same from the inside:
- the database refused the write — nothing happened, and the person who
clicked has to be told, because a silent reaction is indistinguishable
from a bot that is not running;
- Discord could not be reached — after a commit, the thing is recorded
whether or not the message got through, and must stay recorded;
- something else went wrong — a defect, which has to reach a traceback
rather than be flattened into "Error handling attendance confirmation".
The coroutines are driven with `asyncio.run` rather than pytest-asyncio,
which the project does not depend on — same convention as
`test_discord_delivery.py`.
"""
import asyncio
import logging
from datetime import date, time
import pytest
from discord import HTTPException
from sqlalchemy.exc import OperationalError
from app import discord_bot
from app.discord_bot import TeamTryoutsBot
class FakeChannel:
"""The DM channel a reaction came from. Records what it was told to say."""
def __init__(self, raises=None):
self.raises = raises
self.sent = []
async def send(self, message):
if self.raises is not None:
raise self.raises
self.sent.append(message)
return object()
class FakeReactor:
"""The Discord account that clicked. Only its snowflake is ever read."""
def __init__(self, uid):
self.id = uid
def http_error():
class _Response:
status = 500
reason = 'test'
return HTTPException(_Response(), 'Internal Server Error')
def database_error():
"""A refusal that is not an IntegrityError.
Deliberately: the handlers catch `SQLAlchemyError`, and picking the
subclass a constraint violation produces would let a narrower catch
pass this suite while still dropping a lost connection on the floor.
"""
return OperationalError('SELECT 1', {}, Exception('server closed the connection'))
@pytest.fixture
def logs(caplog):
"""Let the bot's records reach caplog.
`configure_logging` sets propagate = False on the 'app' logger, and
caplog's handler sits on the root. Without this the assertions below
read an empty log and pass for the wrong reason — the trap recorded in
the wave G notes.
"""
package_logger = logging.getLogger('app')
previous = package_logger.propagate
package_logger.propagate = True
caplog.set_level(logging.INFO, logger='app.discord_bot')
yield caplog
package_logger.propagate = previous
@pytest.fixture
def bot():
"""A bot with the state the reaction handlers touch, and nothing else.
`__new__` because the constructor builds a real discord.py client.
`_save_pending` is replaced: the real one writes `discord_pending.json`
at the repository root.
"""
instance = TeamTryoutsBot.__new__(TeamTryoutsBot)
instance.flask_app = None
instance.pending_requests = {}
instance._user_cache = {}
instance.reminders_scheduled = False
instance.saves = 0
def _save():
instance.saves += 1
instance._save_pending = _save
return instance
@pytest.fixture
def participation(db, make_user):
"""A player on a match, plus the pending message asking them to confirm.
Returns (participation row id, the player's Discord snowflake).
"""
from app.models import Match, MatchParticipant, Tryout
snowflake = '4242'
player_id = make_user('player', discord_user_id=snowflake)
admin_id = make_user('admin')
tryout = Tryout(title='Sélection', game='valorant', date=date(2026, 9, 1), created_by=admin_id)
db.session.add(tryout)
db.session.flush()
match = Match(
title='Finale',
date=date(2026, 9, 2),
start_time=time(18, 0),
created_by=admin_id,
tryout_id=tryout.id,
match_type='intra',
)
db.session.add(match)
db.session.flush()
row = MatchParticipant(match_id=match.id, player_id=player_id)
db.session.add(row)
db.session.commit()
return row.id, snowflake
def _pending(bot, message_id, row_id):
bot.pending_requests[message_id] = {
'type': 'schedule_addition',
'id': row_id,
'event_type': 'match',
}
def _confirmed(row_id):
from app.models import MatchParticipant
return MatchParticipant.query.get(row_id).attendance_confirmed
class TestTheDatabaseRefusedTheWrite:
def test_the_happy_path_records_the_confirmation(self, bot, db, participation, logs):
"""The premise of every test below. Without it they could all pass
against a handler that never records anything at all."""
row_id, snowflake = participation
_pending(bot, 7, row_id)
channel = FakeChannel()
asyncio.run(bot.handle_attendance_confirm(FakeReactor(snowflake), 7, row_id, channel))
assert _confirmed(row_id) is True
assert channel.sent == ["✅ Your attendance has been confirmed!"]
assert 7 not in bot.pending_requests
def test_a_refused_commit_tells_the_player_instead_of_going_quiet(
self, bot, db, participation, monkeypatch, logs
):
"""The defect ARCH-008 was written about.
The success message sat inside the same blanket handler as the
commit, so a refused write produced no message at all — the reaction
looked ignored, which is what a stopped bot looks like too.
"""
row_id, snowflake = participation
_pending(bot, 7, row_id)
channel = FakeChannel()
def refuse():
raise database_error()
monkeypatch.setattr(db.session, 'commit', refuse)
asyncio.run(bot.handle_attendance_confirm(FakeReactor(snowflake), 7, row_id, channel))
assert channel.sent, 'silence is the one answer this must never give'
assert 'Nothing was recorded' in channel.sent[0]
# Every message, not just the first: an earlier version of this test
# looked at sent[0] alone, and a handler that reported the refusal
# and then sent "✅ Your attendance has been confirmed!" anyway
# passed it.
assert not any("✅" in message for message in channel.sent), (
'a failed write must not be followed by a success message'
)
def test_a_refused_commit_leaves_the_row_untouched(
self, bot, db, participation, monkeypatch, logs
):
row_id, snowflake = participation
_pending(bot, 7, row_id)
def refuse():
raise database_error()
monkeypatch.setattr(db.session, 'commit', refuse)
asyncio.run(bot.handle_attendance_confirm(FakeReactor(snowflake), 7, row_id, FakeChannel()))
monkeypatch.undo()
assert _confirmed(row_id) is False, (
'the handler must roll back; leaving the change pending in the '
'session hands it to whatever commits next'
)
def test_a_refused_commit_keeps_the_reaction_answerable(
self, bot, db, participation, monkeypatch, logs
):
"""Dropping the pending entry on a failed write would make the
second attempt do nothing, silently, forever."""
row_id, snowflake = participation
_pending(bot, 7, row_id)
def refuse():
raise database_error()
monkeypatch.setattr(db.session, 'commit', refuse)
asyncio.run(bot.handle_attendance_confirm(FakeReactor(snowflake), 7, row_id, FakeChannel()))
assert 7 in bot.pending_requests
def test_the_refusal_reaches_the_log_with_its_traceback(
self, bot, db, participation, monkeypatch, logs
):
row_id, snowflake = participation
_pending(bot, 7, row_id)
def refuse():
raise database_error()
monkeypatch.setattr(db.session, 'commit', refuse)
with logs.at_level(logging.ERROR, logger='app.discord_bot'):
asyncio.run(
bot.handle_attendance_confirm(FakeReactor(snowflake), 7, row_id, FakeChannel())
)
assert any(record.exc_info for record in logs.records), (
'a database refusal is diagnosed from the driver error, which only '
'the traceback carries'
)
def test_a_declined_match_that_cannot_be_deleted_says_so(
self, bot, db, participation, monkeypatch, logs
):
"""The decline path deletes a row, which is exactly what a foreign
key refuses. Same answer as the confirm path."""
row_id, snowflake = participation
_pending(bot, 7, row_id)
channel = FakeChannel()
def refuse():
raise database_error()
monkeypatch.setattr(db.session, 'commit', refuse)
asyncio.run(bot.handle_attendance_decline(FakeReactor(snowflake), 7, row_id, channel))
assert channel.sent and 'Nothing was recorded' in channel.sent[0]
assert 7 in bot.pending_requests
class TestDiscordCouldNotBeReached:
def test_a_bounced_message_does_not_undo_the_record(self, bot, db, participation, logs):
"""The confirmation is committed before the message goes out. A DM
that bounces costs the player a message, not their attendance."""
row_id, snowflake = participation
_pending(bot, 7, row_id)
asyncio.run(
bot.handle_attendance_confirm(
FakeReactor(snowflake), 7, row_id, FakeChannel(raises=http_error())
)
)
assert _confirmed(row_id) is True
assert 7 not in bot.pending_requests, (
'the answer is durable, so the message must not stay answerable'
)
def test_a_bounced_message_is_reported(self, bot, db, participation, logs):
row_id, snowflake = participation
_pending(bot, 7, row_id)
with logs.at_level(logging.ERROR, logger='app.discord_bot'):
asyncio.run(
bot.handle_attendance_confirm(
FakeReactor(snowflake), 7, row_id, FakeChannel(raises=http_error())
)
)
assert 'Could not answer a reaction' in logs.text
class TestAnythingElseIsADefect:
def test_an_unexpected_failure_propagates(self, bot, db, participation, monkeypatch, logs):
"""It used to be caught here and logged as though it were a delivery
problem. Letting it out is what puts it in front of on_error."""
row_id, snowflake = participation
_pending(bot, 7, row_id)
def boom(event_type, reference_id):
raise ZeroDivisionError('a defect, not an outage')
monkeypatch.setattr(TeamTryoutsBot, '_attendance_record', staticmethod(boom))
with pytest.raises(ZeroDivisionError):
asyncio.run(
bot.handle_attendance_confirm(FakeReactor(snowflake), 7, row_id, FakeChannel())
)
def test_on_error_records_it_under_this_application_s_logger(self, bot, logs):
"""discord.py logs escaped event exceptions on the `discord` logger,
which logging_config does not wire to any of this application's
files. That is where these used to go."""
with logs.at_level(logging.ERROR, logger='app.discord_bot'):
try:
raise ZeroDivisionError('boom')
except ZeroDivisionError:
asyncio.run(bot.on_error('on_raw_reaction_add'))
assert 'on_raw_reaction_add' in logs.text
assert 'defect' in logs.text
assert any(record.exc_info for record in logs.records)
class TestTheQueueBoundary:
def test_queueing_never_raises_into_the_request_that_caused_it(self, monkeypatch, logs):
"""This runs in a Flask request thread, after the work it announces
is committed. A notification must not turn a finished page into a
500 — but it must not swallow the reason either."""
def no_bot():
raise RuntimeError('the bot could not be built')
monkeypatch.setattr(discord_bot, 'get_bot', no_bot)
with logs.at_level(logging.ERROR, logger='app.discord_bot'):
queued = discord_bot.send_schedule_notification(1, 'match', 'Finale', 'd', 't', 2)
assert queued is False
assert any(record.exc_info for record in logs.records)
def test_a_queued_notification_reaches_the_queue(self, bot, monkeypatch):
"""The premise of the test above: the same call succeeds normally."""
from queue import Queue
bot.message_queue = Queue()
monkeypatch.setattr(discord_bot, 'get_bot', lambda: bot)
assert discord_bot.send_schedule_notification(1, 'match', 'Finale', 'd', 't', 2) is True
assert bot.message_queue.get_nowait()['type'] == 'schedule_addition'
def test_an_unknown_item_type_is_named_and_dropped(self, bot, logs):
with logs.at_level(logging.ERROR, logger='app.discord_bot'):
asyncio.run(bot._dispatch({'type': 'invented', 'data': {}}))
assert 'invented' in logs.text
class TestTheSchedulerSaysWhetherItStarted:
class FailingScheduler:
@staticmethod
def add_job(*args, **kwargs):
raise RuntimeError('no event loop')
class WorkingScheduler:
def __init__(self):
self.started = False
def add_job(self, *args, **kwargs):
pass
def start(self):
self.started = True
def test_a_scheduler_that_will_not_start_is_visible_from_outside(self, bot, logs):
"""The other four /health keys all read green in this state: the
thread is alive, the gateway is up, and no reminder is ever sent."""
from zoneinfo import ZoneInfo
bot.scheduler = self.FailingScheduler()
bot.timezone = ZoneInfo('America/Toronto')
with logs.at_level(logging.ERROR, logger='app.discord_bot'):
asyncio.run(bot.start_scheduler())
assert bot.reminders_scheduled is False
assert 'No reminder will be sent' in logs.text
def test_a_scheduler_that_starts_says_so(self, bot, logs):
from zoneinfo import ZoneInfo
bot.scheduler = self.WorkingScheduler()
bot.timezone = ZoneInfo('America/Toronto')
asyncio.run(bot.start_scheduler())
assert bot.scheduler.started is True
assert bot.reminders_scheduled is True
class TestTwoReactionsOnOneMessage:
def test_the_second_one_finds_nothing_to_do(self, bot, db, participation, logs):
"""A confirm and a decline arrive together; both got past the
membership check in on_raw_reaction_add before either finished. The
loser used to raise KeyError inside the blanket handler, where it
read as an error with no consequence."""
row_id, snowflake = participation
_pending(bot, 7, row_id)
reactor = FakeReactor(snowflake)
asyncio.run(bot.handle_attendance_confirm(reactor, 7, row_id, FakeChannel()))
second = FakeChannel()
asyncio.run(bot.handle_attendance_decline(reactor, 7, row_id, second))
assert second.sent == [], 'the second reaction must not answer twice'
assert _confirmed(row_id) is True
tests/test_discord_state.py
+16 -2
View File
@@ -143,15 +143,29 @@ class TestLoading:
class TestHealthReporting:
def test_the_status_shape_is_stable(self, monkeypatch):
"""An external probe reads these keys; they are the contract."""
"""An external probe reads these keys; they are the contract.
`reminders_scheduled` joined them with ARCH-008. The other four can
all read green while the 18:00 job never got scheduled — the thread
is alive, the gateway is up, and no reminder is ever sent. Adding a
key is safe for a probe that looks at the ones it knows; removing or
renaming one is not.
"""
monkeypatch.setattr(discord_bot, 'bot_thread', None)
monkeypatch.setattr(discord_bot, 'bot_instance', None)
status = discord_bot.bot_status()
assert set(status) == {'configured', 'running', 'connected', 'pending'}
assert set(status) == {
'configured',
'running',
'connected',
'pending',
'reminders_scheduled',
}
assert status['running'] is False
assert status['connected'] is False
assert status['reminders_scheduled'] is False
def test_a_dead_thread_reads_as_not_running(self, monkeypatch):
class DeadThread: