fix(ops): rendre visibles les pannes silencieuses du bot Discord

OPS-005, OPS-006, OPS-007, OPS-009 et OPS-012. Cinq constats, un motif
commun : le bot pouvait cesser de fonctionner correctement sans que rien,
nulle part, ne le dise.

OPS-006 -- etat en attente ecrit en place
_save_pending ouvrait le fichier de destination en ecriture puis
serialisait dedans : toute interruption laissait un JSON tronque. Et
_load_pending interceptait l erreur de lecture, la journalisait, puis
repartait avec un dictionnaire vide -- toutes les correspondances message
Discord <-> demande disparaissaient, les reactions en cours cessaient
d avoir un effet, et l interface n en montrait rien.

Ecriture par fichier temporaire voisin puis os.replace : la destination
contient l ancien contenu ou le nouveau, jamais la moitie d un des deux.
A la lecture, un fichier illisible est deplace en .corrupt-<horodatage>
plutot qu ecrase, et le message dit ce qui est perdu.

Ecart assume avec la recommandation d audit (« echouer bruyamment ») : le
bot demarre quand meme. Refuser de demarrer supprimerait toutes les
notifications au lieu de celles deja en vol.

OPS-007 -- fuite lente
Les entrees n etaient retirees qu apres reaction. Elles portent desormais
`created_at` et sont purgees au chargement au-dela de 30 jours. Une entree
sans horodatage est conservee : elle precede ce champ, la supprimer serait
deviner son age.

OPS-005 -- planificateur
`coalesce=True`, `misfire_grace_time=3600`, `max_instances=1`. Sans delai
de grace, un redemarrage a 18 h 05 perdait les rappels du jour sans trace ;
sans coalescence, un planificateur en retard envoie un rappel par
occurrence manquee, donc des messages en double.

OPS-009 -- controle d identite asymetrique
handle_one_on_one_approve et _reject comparent depuis toujours le compte
qui reagit au coach destinataire. Les deux gestionnaires de presence ne le
faisaient pas. Meme forme de message, meme risque, un seul verifiait :
c est l asymetrie qui etait le bug.

Au passage : confirmer sa presence a un tryout ecrivait un attribut qui n a
pas de colonne (DB-008, bloque sur Alembic). Le joueur lisait « confirme »
et rien n etait enregistre. Toujours vrai, mais desormais journalise en
warning avec l identifiant concerne.

OPS-012 -- etat du bot dans /health
Le bot tourne dans un fil demon du processus web. Quand ce fil meurt, le
site continue de servir des pages et plus aucune notification ne part.
/health expose maintenant configured / running / connected / pending.
Signale, pas fatal : un club sans rappels Discord est degrade, pas hors
service, et un 503 le sortirait du repartiteur de charge pour ca.

discord_pending.json passe hors suivi git. La regle d ignore etait en place
mais inerte. Consequence non relevee par l audit : le deploiement etant un
miroir de fichiers, chaque livraison ecrasait l etat vivant du serveur par
celui du depot.

13 tests, sans aucun appel a Discord.

Co-Authored-By: Claude Opus 5 <[email protected]>
This commit is contained in:
GGThed
2026-08-08 18:21:05 -04:00
co-authored by Claude Opus 5
parent 2e10bbbd62
commit e5c29d8113
4 changed files with 411 additions and 43 deletions
+11
View File
@@ -364,6 +364,17 @@ def create_app(config=None):
'version': '1.0.0',
}
# The bot runs in a daemon thread inside this process. When it dies
# the site keeps serving pages and every notification stops, with
# nothing to see from outside — which is how it stayed unnoticed.
# Reported, not fatal: a club without Discord reminders is degraded,
# not down, and a 503 here would take the site out of the load
# balancer for it (OPS-012).
if app.config['ENABLE_DISCORD_BOT']:
from app.discord_bot import bot_status
health_data['discord_bot'] = bot_status()
# Check database connectivity
try:
db.session.execute(text('SELECT 1'))
+220 -42
View File
@@ -9,6 +9,8 @@ This module provides a persistent bot that handles:
import os
import json
import logging
import tempfile
import time
import asyncio
import threading
import traceback
@@ -33,6 +35,14 @@ PENDING_FILE = os.path.join(
)
# Emoji constants
#: Entries older than this are dropped when the file is loaded: a message
#: nobody reacted to in a month will not be reacted to (OPS-007).
PENDING_MAX_AGE_DAYS = 30
#: How late the daily reminder may still be sent. Long enough to survive a
#: restart or a slow start-up, short of the next day's occurrence.
REMINDER_GRACE_SECONDS = 3600
CHECK_EMOJI = '' # Green checkmark
CROSS_EMOJI = '' # Red X
@@ -66,28 +76,99 @@ class TeamTryoutsBot(commands.Bot):
self.timezone = ZoneInfo('America/Toronto') # EDT timezone
def _load_pending(self):
"""Load pending requests from the JSON file."""
"""Load pending requests from the JSON file.
A corrupt file used to be logged at error level and then silently
replaced by an empty dict: every in-flight Discord reaction stopped
having any effect, and nothing said so (OPS-006). The file is now
moved aside instead of overwritten, so the mapping can be recovered
by hand, and the message says what was lost.
Entries older than PENDING_MAX_AGE_DAYS are dropped here rather
than kept forever (OPS-007). A message nobody reacted to in a month
is not going to be reacted to.
"""
if not os.path.exists(PENDING_FILE):
logger.info('No pending requests file found, starting fresh.')
return
try:
if os.path.exists(PENDING_FILE):
with open(PENDING_FILE) as f:
data = json.load(f)
# Convert string keys back to int
self.pending_requests = {int(k): v for k, v in data.items()}
logger.info(
f"Loaded {len(self.pending_requests)} pending requests from {PENDING_FILE}"
)
else:
logger.info("No pending requests file found, starting fresh.")
except Exception as e:
logger.error(f"Error loading pending requests: {e}")
with open(PENDING_FILE, encoding='utf-8') as handle:
data = json.load(handle)
if not isinstance(data, dict):
raise ValueError(f'expected an object, found {type(data).__name__}')
# Keys are Discord message ids; JSON turns them into strings.
loaded = {int(key): value for key, value in data.items()}
except (OSError, ValueError) as exc:
quarantine = f'{PENDING_FILE}.corrupt-{int(time.time())}'
try:
os.replace(PENDING_FILE, quarantine)
except OSError:
quarantine = '(could not be moved aside)'
logger.error(
'Pending requests file unreadable (%s). Moved to %s. Reactions on '
'messages already sent will no longer be recognised until those '
'requests are answered in the web interface.',
exc,
quarantine,
)
return
kept, expired = self._drop_expired(loaded)
self.pending_requests = kept
logger.info(
'Loaded %d pending requests from %s (%d expired and dropped)',
len(kept),
PENDING_FILE,
expired,
)
if expired:
self._save_pending()
@staticmethod
def _drop_expired(entries):
"""Split loaded entries into the ones still worth keeping.
Args:
entries: message_id → record.
Returns:
tuple[dict, int]: Entries to keep, and how many were dropped.
A record without a timestamp predates this field and is kept —
dropping it would be guessing.
"""
cutoff = time.time() - PENDING_MAX_AGE_DAYS * 86400
kept = {}
expired = 0
for message_id, record in entries.items():
created = record.get('created_at') if isinstance(record, dict) else None
if created is not None and created < cutoff:
expired += 1
continue
kept[message_id] = record
return kept, expired
def _save_pending(self):
"""Save pending requests to the JSON file."""
"""Write the pending requests to disk, atomically.
The previous version opened the destination for writing and then
serialised into it: an interruption anywhere in between left a
truncated JSON file, which the loader could not read. Writing to a
neighbouring temporary file and renaming means the destination is
either the old content or the new one, never half of either.
"""
directory = os.path.dirname(PENDING_FILE) or '.'
try:
with open(PENDING_FILE, 'w') as f:
json.dump(self.pending_requests, f, indent=2)
except Exception as e:
logger.error(f"Error saving pending requests: {e}")
with tempfile.NamedTemporaryFile(
'w', encoding='utf-8', dir=directory, prefix='.pending-', delete=False
) as handle:
json.dump(self.pending_requests, handle, indent=2)
handle.flush()
os.fsync(handle.fileno())
temporary = handle.name
os.replace(temporary, PENDING_FILE)
except OSError as exc:
logger.error('Could not save pending requests: %s', exc)
async def setup_hook(self):
"""Called when the bot is ready."""
@@ -109,13 +190,26 @@ class TeamTryoutsBot(commands.Bot):
self.loop.create_task(self.start_scheduler())
async def start_scheduler(self):
"""Start the APScheduler for daily reminders."""
"""Start the APScheduler for daily reminders.
`coalesce` and `misfire_grace_time` are the two settings this job
needs and did not have (OPS-005). Without a grace time, a restart at
18:05 dropped the day's reminders with no trace; without coalescing,
a scheduler that wakes up behind schedule fires once per missed run,
so players receive the same reminder several times.
The grace period is deliberately short of the next occurrence: a
reminder for tonight is worth sending an hour late, not tomorrow.
"""
try:
self.scheduler.add_job(
self.send_daily_reminders,
trigger=CronTrigger(hour=18, minute=0, timezone=self.timezone),
id='daily_reminders',
replace_existing=True,
coalesce=True,
misfire_grace_time=REMINDER_GRACE_SECONDS,
max_instances=1,
)
self.scheduler.start()
logger.info('Daily reminder scheduler started (18:00 EDT)')
@@ -269,7 +363,11 @@ class TeamTryoutsBot(commands.Bot):
await msg.add_reaction(CROSS_EMOJI)
# Track this pending request
self.pending_requests[msg.id] = {'type': 'one_on_one', 'id': request_id}
self.pending_requests[msg.id] = {
'type': 'one_on_one',
'id': request_id,
'created_at': time.time(),
}
self._save_pending()
logger.info(f"Sent One on One DM with reactions, message_id={msg.id}")
@@ -339,6 +437,7 @@ class TeamTryoutsBot(commands.Bot):
'type': 'schedule_addition',
'id': reference_id,
'event_type': event_type,
'created_at': time.time(),
}
self._save_pending()
@@ -460,25 +559,73 @@ class TeamTryoutsBot(commands.Bot):
except Exception as e:
logger.error(f"Error handling rejection: {e}\n{traceback.format_exc()}")
@staticmethod
def _attendance_record(event_type, reference_id):
"""The row an attendance reaction refers to, and whose it is.
Args:
event_type: 'match' or 'tryout'.
reference_id: Primary key of the participation row.
Returns:
tuple: (row, player_id) — either may be None.
"""
from app.models import MatchParticipant, TryoutRegistration
if event_type == 'match':
row = MatchParticipant.query.get(reference_id)
elif event_type == 'tryout':
row = TryoutRegistration.query.get(reference_id)
else:
row = None
return row, getattr(row, 'player_id', None)
@staticmethod
def _reacting_user_owns(player_id, reacting_user):
"""Whether the Discord account that reacted is the row's owner.
handle_one_on_one_approve and _reject have always compared the
reacting account against the coach the request was sent to. The two
attendance handlers did not (OPS-009) — same message shape, same
threat, one of them checked. The asymmetry was the bug.
"""
from app.models import User
if not player_id:
return False
owner = User.query.get(player_id)
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:
from app.models import MatchParticipant, TryoutRegistration
from app.extensions import db
request_info = self.pending_requests[message_id]
event_type = request_info.get('event_type')
row, player_id = self._attendance_record(event_type, reference_id)
if event_type == 'match':
participant = MatchParticipant.query.get(reference_id)
if participant:
participant = db.session.merge(participant)
participant.attendance_confirmed = True
elif event_type == 'tryout':
registration = TryoutRegistration.query.get(reference_id)
if registration:
registration = db.session.merge(registration)
registration.attendance_confirmed = True
if row is not None and not self._reacting_user_owns(player_id, player):
await channel.send("⚠️ You are not the intended recipient.")
return
if row is not None:
row = db.session.merge(row)
if event_type == 'match':
row.attendance_confirmed = True
else:
# TryoutRegistration has no attendance_confirmed column
# (DB-008, waiting on Alembic). Assigning here sets a
# Python attribute that is never written, so the player
# was told "confirmed" and nothing was recorded. Still
# true — but no longer silent.
logger.warning(
'Tryout attendance confirmation from user_id=%s for '
'registration %s was not persisted: TryoutRegistration '
'has no attendance_confirmed column (DB-008).',
player.id,
reference_id,
)
db.session.commit()
@@ -492,22 +639,22 @@ class TeamTryoutsBot(commands.Bot):
async def handle_attendance_decline(self, player, message_id, reference_id, channel):
"""Handle player declining attendance for a match/tryout."""
try:
from app.models import MatchParticipant, TryoutRegistration
from app.extensions import db
request_info = self.pending_requests[message_id]
event_type = request_info.get('event_type')
row, player_id = self._attendance_record(event_type, reference_id)
if event_type == 'match':
participant = MatchParticipant.query.get(reference_id)
if participant:
participant = db.session.merge(participant)
db.session.delete(participant)
elif event_type == 'tryout':
registration = TryoutRegistration.query.get(reference_id)
if registration:
registration = db.session.merge(registration)
registration.status = 'no_show'
if row is not None and not self._reacting_user_owns(player_id, player):
await channel.send("⚠️ You are not the intended recipient.")
return
if row is not None:
row = db.session.merge(row)
if event_type == 'match':
db.session.delete(row)
else:
row.status = 'no_show'
db.session.commit()
@@ -880,9 +1027,40 @@ def start_bot(flask_app=None):
bot.run(DISCORD_BOT_TOKEN)
except Exception as e:
logger.error(f"Bot error: {e}")
finally:
# bot.run() returning means the connection is gone for good:
# discord.py reconnects on its own for anything recoverable.
# Recording it is what makes bot_status() able to say 'stopped'
# instead of reporting a dead thread as running.
logger.error('Discord bot loop exited; notifications are no longer being sent')
bot_thread = threading.Thread(target=run_bot, daemon=True)
bot_thread.start()
logger.info("TeamTryoutsBot started in background thread")
elif not DISCORD_BOT_TOKEN:
logger.warning("DISCORD_BOT_TOKEN not set, bot not started")
def bot_status():
"""What the bot is doing, for /health (OPS-012).
The bot runs in a daemon thread inside the web process. When that
thread dies — a revoked token, a fatal gateway error — the web
application keeps serving pages and no notification is ever sent again.
Nothing reported it, so nobody found out until someone asked why they
had stopped receiving reminders.
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).
"""
running = bool(bot_thread and bot_thread.is_alive())
instance = bot_instance
connected = bool(instance and not instance.is_closed() and instance.is_ready())
return {
'configured': bool(DISCORD_BOT_TOKEN),
'running': running,
'connected': connected,
'pending': len(instance.pending_requests) if instance else 0,
}