feat(ops): un bot qui tombe se releve, ou dit pourquoi il ne peut pas
OPS-004. bot.run() qui rend la main signifie que la connexion est perdue pour de bon : discord.py se reconnecte seul pour tout ce qui est recuperable. Ce qui se passait ensuite, c'etait rien. Le fil se terminait, bot_thread restait non nul donc start_bot n'en relancerait jamais un autre, et l'application web continuait a servir des pages pendant que toutes les notifications et tous les rappels quotidiens s'etaient arretes. La vague E/F avait fait la moitie visibilite (OPS-012), pas la moitie reprise. La panne pouvait durer des semaines. Deux fins sont distinguees, parce que reessayer ne sert que pour l'une. Un jeton rejete ou un intent privilegie manquant est une erreur de configuration : boucler dessus ne fait que marteler le point de connexion de Discord, ce qui est la maniere d'obtenir une limitation ou un bannissement. Le reste est traite comme une panne et reessaye avec une temporisation exponentielle, plafonnee a cinq minutes, tant que le processus vit. La temporisation se reinitialise apres une connexion qui a dure. Sinon un bot qui tourne un mois puis decroche attend cinq minutes avant son premier essai, fort d'un incident depuis longtemps termine. Deux consequences de conception. Une instance neuve a chaque tentative : discord.py ferme le client quand run() rend la main, et un client ferme ne se reconnecte pas -- le reutiliser transforme une reprise en fil qui tourne sur une exception. Et donc la file de messages passe au niveau module, sinon chaque redemarrage emporterait les notifications en attente. Co-Authored-By: Claude Opus 5 <[email protected]>
This commit is contained in:
+133
-19
@@ -53,7 +53,14 @@ from zoneinfo import ZoneInfo
|
|||||||
|
|
||||||
from apscheduler.schedulers.asyncio import AsyncIOScheduler
|
from apscheduler.schedulers.asyncio import AsyncIOScheduler
|
||||||
from apscheduler.triggers.cron import CronTrigger
|
from apscheduler.triggers.cron import CronTrigger
|
||||||
from discord import Forbidden, HTTPException, Intents, NotFound
|
from discord import (
|
||||||
|
Forbidden,
|
||||||
|
HTTPException,
|
||||||
|
Intents,
|
||||||
|
LoginFailure,
|
||||||
|
NotFound,
|
||||||
|
PrivilegedIntentsRequired,
|
||||||
|
)
|
||||||
from discord.ext import commands
|
from discord.ext import commands
|
||||||
from dotenv import load_dotenv
|
from dotenv import load_dotenv
|
||||||
from sqlalchemy.exc import SQLAlchemyError
|
from sqlalchemy.exc import SQLAlchemyError
|
||||||
@@ -98,6 +105,33 @@ USER_CACHE_MAX = 512
|
|||||||
CHECK_EMOJI = '✅' # Green checkmark
|
CHECK_EMOJI = '✅' # Green checkmark
|
||||||
CROSS_EMOJI = '❌' # Red X
|
CROSS_EMOJI = '❌' # Red X
|
||||||
|
|
||||||
|
#: First wait before restarting a bot that stopped (OPS-004). Short, because
|
||||||
|
#: the common case is a brief network blip.
|
||||||
|
BOT_RESTART_DELAY_SECONDS = 5
|
||||||
|
|
||||||
|
#: Ceiling on that wait. Five minutes is late enough not to hammer Discord
|
||||||
|
#: through a long outage, early enough that nobody plans an evening around
|
||||||
|
#: the reminder never arriving.
|
||||||
|
BOT_RESTART_MAX_DELAY_SECONDS = 300
|
||||||
|
|
||||||
|
#: A connection that lasted this long counts as healthy, and resets the
|
||||||
|
#: back-off. Without it, a bot that ran for a month and then dropped would
|
||||||
|
#: wait five minutes before its first retry, on the strength of an incident
|
||||||
|
#: that is long over.
|
||||||
|
BOT_RESTART_RESET_SECONDS = 600
|
||||||
|
|
||||||
|
#: Notifications waiting for the bot thread.
|
||||||
|
#:
|
||||||
|
#: Module level, not per-instance: the supervisor replaces the bot object on
|
||||||
|
#: every restart, because discord.py cannot reuse a client whose run() has
|
||||||
|
#: returned. A queue living on the old object would be discarded with it,
|
||||||
|
#: taking every pending notification along.
|
||||||
|
message_queue = Queue()
|
||||||
|
|
||||||
|
#: Set to ask the supervisor to stop waiting and return. Only tests set it;
|
||||||
|
#: in production the thread is a daemon and the process exit ends it.
|
||||||
|
_stop_bot = threading.Event()
|
||||||
|
|
||||||
|
|
||||||
class TeamTryoutsBot(commands.Bot):
|
class TeamTryoutsBot(commands.Bot):
|
||||||
"""Unified Discord bot for Team Tryouts notifications.
|
"""Unified Discord bot for Team Tryouts notifications.
|
||||||
@@ -123,7 +157,10 @@ class TeamTryoutsBot(commands.Bot):
|
|||||||
super().__init__(command_prefix='!', intents=intents)
|
super().__init__(command_prefix='!', intents=intents)
|
||||||
self.flask_app = flask_app
|
self.flask_app = flask_app
|
||||||
self.pending_requests = {} # Maps message_id to {type, id} for reaction handling
|
self.pending_requests = {} # Maps message_id to {type, id} for reaction handling
|
||||||
self.message_queue = Queue() # Thread-safe queue for messages from Flask
|
# The shared module-level queue, not a new one: a restart builds a
|
||||||
|
# fresh bot, and notifications queued against the old one must not
|
||||||
|
# go with it (OPS-004).
|
||||||
|
self.message_queue = message_queue
|
||||||
self.scheduler = AsyncIOScheduler()
|
self.scheduler = AsyncIOScheduler()
|
||||||
self.timezone = ZoneInfo('America/Toronto') # EDT timezone
|
self.timezone = ZoneInfo('America/Toronto') # EDT timezone
|
||||||
self._user_cache = {} # Discord snowflake -> User, bounded (PERF-005)
|
self._user_cache = {} # Discord snowflake -> User, bounded (PERF-005)
|
||||||
@@ -1293,12 +1330,25 @@ class TeamTryoutsBot(commands.Bot):
|
|||||||
bot_instance = None
|
bot_instance = None
|
||||||
bot_thread = None
|
bot_thread = None
|
||||||
|
|
||||||
|
#: The application the bot binds its database work to. Held separately from
|
||||||
|
#: the instance because the supervisor discards the instance on restart and
|
||||||
|
#: has to build the next one with the same application (OPS-004).
|
||||||
|
bot_flask_app = None
|
||||||
|
|
||||||
|
|
||||||
def get_bot(flask_app=None):
|
def get_bot(flask_app=None):
|
||||||
"""Get or create the bot instance."""
|
"""Get or create the bot instance.
|
||||||
global bot_instance
|
|
||||||
|
Falls back to the application the supervisor was started with, so that
|
||||||
|
a bot rebuilt after a disconnection still reaches the database — the
|
||||||
|
caller that has the application is `create_app`, and it only calls this
|
||||||
|
once (OPS-004).
|
||||||
|
"""
|
||||||
|
global bot_instance, bot_flask_app
|
||||||
|
if flask_app is not None:
|
||||||
|
bot_flask_app = flask_app
|
||||||
if bot_instance is None:
|
if bot_instance is None:
|
||||||
bot_instance = TeamTryoutsBot(flask_app=flask_app)
|
bot_instance = TeamTryoutsBot(flask_app=flask_app or bot_flask_app)
|
||||||
elif flask_app is not None and bot_instance.flask_app is None:
|
elif flask_app is not None and bot_instance.flask_app is None:
|
||||||
bot_instance.flask_app = flask_app
|
bot_instance.flask_app = flask_app
|
||||||
return bot_instance
|
return bot_instance
|
||||||
@@ -1410,26 +1460,90 @@ def send_one_on_one_response(
|
|||||||
)
|
)
|
||||||
|
|
||||||
|
|
||||||
def start_bot(flask_app=None):
|
def supervise_bot(run_once=False):
|
||||||
"""Start the Discord bot in the background."""
|
"""Keep a Discord bot running, or say clearly why one will not be.
|
||||||
global bot_thread
|
|
||||||
|
|
||||||
bot = get_bot(flask_app=flask_app)
|
`bot.run()` returning means the connection is gone for good — discord.py
|
||||||
if DISCORD_BOT_TOKEN and bot_thread is None:
|
reconnects on its own for anything recoverable. What happened next was
|
||||||
|
nothing: the thread ended, `bot_thread` stayed non-None so `start_bot`
|
||||||
|
would never start another, and the web application went on serving pages
|
||||||
|
while every notification and every daily reminder had stopped. Nothing
|
||||||
|
reported it; the outage could last weeks (OPS-004).
|
||||||
|
|
||||||
|
Two kinds of ending are told apart, because retrying helps with exactly
|
||||||
|
one of them. A rejected token or a missing privileged intent is a
|
||||||
|
configuration error: retrying it accomplishes nothing except hammering
|
||||||
|
Discord's login endpoint, which is how an application gets rate-limited
|
||||||
|
or banned outright. Everything else is treated as an outage and retried
|
||||||
|
with an exponential back-off, capped, for as long as the process lives.
|
||||||
|
|
||||||
|
The back-off resets after a connection that lasted. Otherwise a bot that
|
||||||
|
runs happily for a month and then drops would wait five minutes before
|
||||||
|
its first retry, having "learned" from an incident that is long over.
|
||||||
|
|
||||||
|
Args:
|
||||||
|
run_once: Stop after a single attempt. For tests — the production
|
||||||
|
caller never sets it.
|
||||||
|
"""
|
||||||
|
global bot_instance
|
||||||
|
|
||||||
|
delay = BOT_RESTART_DELAY_SECONDS
|
||||||
|
while True:
|
||||||
|
# A fresh instance every time, deliberately. discord.py closes the
|
||||||
|
# client when run() returns, and a closed Client will not log in
|
||||||
|
# again — reusing it is how a "restart" turns into a thread that
|
||||||
|
# spins on an exception. This is also why message_queue lives at
|
||||||
|
# module level: a queue on the old object would take every pending
|
||||||
|
# notification with it.
|
||||||
|
bot = get_bot(flask_app=bot_flask_app)
|
||||||
|
started = time.monotonic()
|
||||||
|
|
||||||
def run_bot():
|
|
||||||
try:
|
try:
|
||||||
bot.run(DISCORD_BOT_TOKEN)
|
bot.run(DISCORD_BOT_TOKEN)
|
||||||
|
except (LoginFailure, PrivilegedIntentsRequired) as exc:
|
||||||
|
logger.error(
|
||||||
|
'The Discord bot cannot log in (%s). This is a configuration error, '
|
||||||
|
'not an outage: retrying would only hammer the login endpoint. No '
|
||||||
|
'notification will be sent until the token or the intents are fixed '
|
||||||
|
'and the process is restarted.',
|
||||||
|
type(exc).__name__,
|
||||||
|
)
|
||||||
|
return
|
||||||
except Exception: # top of a thread; there is nothing above to catch it
|
except Exception: # top of a thread; there is nothing above to catch it
|
||||||
logger.exception('The Discord bot thread stopped on an unhandled error')
|
logger.exception('The Discord bot stopped on an unhandled error')
|
||||||
finally:
|
else:
|
||||||
# bot.run() returning means the connection is gone for good:
|
logger.error('The Discord bot disconnected and did not recover on its own')
|
||||||
# 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_instance = None
|
||||||
|
|
||||||
|
if time.monotonic() - started >= BOT_RESTART_RESET_SECONDS:
|
||||||
|
delay = BOT_RESTART_DELAY_SECONDS
|
||||||
|
|
||||||
|
if run_once:
|
||||||
|
return
|
||||||
|
|
||||||
|
logger.warning(
|
||||||
|
'Restarting the Discord bot in %ds. Notifications are not being sent '
|
||||||
|
'until it reconnects.',
|
||||||
|
delay,
|
||||||
|
)
|
||||||
|
if _stop_bot.wait(delay):
|
||||||
|
logger.info('Discord bot supervisor asked to stop.')
|
||||||
|
return
|
||||||
|
delay = min(delay * 2, BOT_RESTART_MAX_DELAY_SECONDS)
|
||||||
|
|
||||||
|
|
||||||
|
def start_bot(flask_app=None):
|
||||||
|
"""Start the supervised Discord bot in a background thread."""
|
||||||
|
global bot_thread, bot_flask_app
|
||||||
|
|
||||||
|
if flask_app is not None:
|
||||||
|
bot_flask_app = flask_app
|
||||||
|
get_bot(flask_app=flask_app)
|
||||||
|
|
||||||
|
if DISCORD_BOT_TOKEN and bot_thread is None:
|
||||||
|
_stop_bot.clear()
|
||||||
|
bot_thread = threading.Thread(target=supervise_bot, daemon=True)
|
||||||
bot_thread.start()
|
bot_thread.start()
|
||||||
logger.info("TeamTryoutsBot started in background thread")
|
logger.info("TeamTryoutsBot started in background thread")
|
||||||
elif not DISCORD_BOT_TOKEN:
|
elif not DISCORD_BOT_TOKEN:
|
||||||
|
|||||||
@@ -17,6 +17,7 @@ These tests drive the bot object directly. Nothing here talks to Discord.
|
|||||||
"""
|
"""
|
||||||
|
|
||||||
import json
|
import json
|
||||||
|
import logging
|
||||||
import os
|
import os
|
||||||
import time
|
import time
|
||||||
|
|
||||||
@@ -192,3 +193,158 @@ class TestHealthReporting:
|
|||||||
payload = client.get('/health').get_json()
|
payload = client.get('/health').get_json()
|
||||||
|
|
||||||
assert 'discord_bot' not in payload
|
assert 'discord_bot' not in payload
|
||||||
|
|
||||||
|
|
||||||
|
class TestTheSupervisorRestartsTheBot:
|
||||||
|
"""OPS-004 — nothing used to restart it.
|
||||||
|
|
||||||
|
`bot.run()` returning means the connection is gone for good; discord.py
|
||||||
|
reconnects on its own for anything recoverable. The thread then ended,
|
||||||
|
`bot_thread` stayed non-None so `start_bot` would never start another,
|
||||||
|
and the web application kept serving pages while every notification and
|
||||||
|
every daily reminder had stopped. The outage could last weeks.
|
||||||
|
"""
|
||||||
|
|
||||||
|
@pytest.fixture
|
||||||
|
def supervisor(self, monkeypatch):
|
||||||
|
"""Drive supervise_bot without a network, a token or a real client.
|
||||||
|
|
||||||
|
Returns a recorder holding the sequence of fake bots that were built
|
||||||
|
and how long the supervisor waited between them.
|
||||||
|
"""
|
||||||
|
|
||||||
|
class Recorder:
|
||||||
|
def __init__(self):
|
||||||
|
self.built = []
|
||||||
|
self.waits = []
|
||||||
|
self.outcomes = []
|
||||||
|
|
||||||
|
recorder = Recorder()
|
||||||
|
|
||||||
|
class FakeBot:
|
||||||
|
def __init__(self, outcome):
|
||||||
|
self.outcome = outcome
|
||||||
|
|
||||||
|
def run(self, _token):
|
||||||
|
# Returning is what discord.py does on a clean disconnection;
|
||||||
|
# raising is the other half of what the supervisor separates.
|
||||||
|
if isinstance(self.outcome, Exception):
|
||||||
|
raise self.outcome
|
||||||
|
|
||||||
|
def fake_get_bot(flask_app=None):
|
||||||
|
outcome = recorder.outcomes.pop(0) if recorder.outcomes else None
|
||||||
|
bot = FakeBot(outcome)
|
||||||
|
recorder.built.append(bot)
|
||||||
|
return bot
|
||||||
|
|
||||||
|
def fake_wait(seconds):
|
||||||
|
recorder.waits.append(seconds)
|
||||||
|
# False means "not asked to stop", so the loop continues. The
|
||||||
|
# test bounds the run by emptying `outcomes` and setting the
|
||||||
|
# event, never by sleeping.
|
||||||
|
return recorder.stop_after_waits <= len(recorder.waits)
|
||||||
|
|
||||||
|
recorder.stop_after_waits = 1
|
||||||
|
monkeypatch.setattr(discord_bot, 'get_bot', fake_get_bot)
|
||||||
|
monkeypatch.setattr(discord_bot, 'DISCORD_BOT_TOKEN', 'token-not-real')
|
||||||
|
monkeypatch.setattr(discord_bot._stop_bot, 'wait', fake_wait)
|
||||||
|
monkeypatch.setattr(discord_bot, 'bot_instance', None)
|
||||||
|
return recorder
|
||||||
|
|
||||||
|
def test_a_disconnection_builds_a_new_bot(self, supervisor, monkeypatch):
|
||||||
|
"""A fresh instance, not the old one: discord.py closes the client
|
||||||
|
when run() returns and a closed client will not log in again."""
|
||||||
|
supervisor.stop_after_waits = 2
|
||||||
|
|
||||||
|
discord_bot.supervise_bot()
|
||||||
|
|
||||||
|
assert len(supervisor.built) == 2, 'the supervisor did not try again'
|
||||||
|
assert supervisor.built[0] is not supervisor.built[1]
|
||||||
|
|
||||||
|
def test_the_wait_grows_between_attempts(self, supervisor):
|
||||||
|
supervisor.stop_after_waits = 4
|
||||||
|
|
||||||
|
discord_bot.supervise_bot()
|
||||||
|
|
||||||
|
assert supervisor.waits == [5, 10, 20, 40]
|
||||||
|
|
||||||
|
def test_the_wait_is_capped(self, supervisor):
|
||||||
|
supervisor.stop_after_waits = 12
|
||||||
|
|
||||||
|
discord_bot.supervise_bot()
|
||||||
|
|
||||||
|
assert max(supervisor.waits) == discord_bot.BOT_RESTART_MAX_DELAY_SECONDS
|
||||||
|
assert supervisor.waits[-1] == discord_bot.BOT_RESTART_MAX_DELAY_SECONDS
|
||||||
|
|
||||||
|
def test_a_rejected_token_is_not_retried(self, supervisor, caplog):
|
||||||
|
"""Retrying a bad token accomplishes nothing except hammering the
|
||||||
|
login endpoint, which is how an application gets rate-limited."""
|
||||||
|
from discord import LoginFailure
|
||||||
|
|
||||||
|
supervisor.outcomes = [LoginFailure('Improper token has been passed.')]
|
||||||
|
supervisor.stop_after_waits = 99
|
||||||
|
|
||||||
|
discord_bot.supervise_bot()
|
||||||
|
|
||||||
|
assert supervisor.waits == [], 'a configuration error must not be retried'
|
||||||
|
assert len(supervisor.built) == 1
|
||||||
|
|
||||||
|
def test_a_rejected_token_says_it_is_a_configuration_error(self, supervisor, caplog):
|
||||||
|
from discord import LoginFailure
|
||||||
|
|
||||||
|
supervisor.outcomes = [LoginFailure('Improper token has been passed.')]
|
||||||
|
|
||||||
|
package_logger = logging.getLogger('app')
|
||||||
|
previous = package_logger.propagate
|
||||||
|
package_logger.propagate = True
|
||||||
|
try:
|
||||||
|
with caplog.at_level(logging.ERROR, logger='app.discord_bot'):
|
||||||
|
discord_bot.supervise_bot()
|
||||||
|
finally:
|
||||||
|
package_logger.propagate = previous
|
||||||
|
|
||||||
|
assert 'configuration error' in caplog.text
|
||||||
|
assert 'not an outage' in caplog.text
|
||||||
|
|
||||||
|
def test_an_unexpected_error_is_retried(self, supervisor):
|
||||||
|
"""The other branch: anything that is not a login refusal is treated
|
||||||
|
as an outage."""
|
||||||
|
supervisor.outcomes = [RuntimeError('gateway exploded')]
|
||||||
|
supervisor.stop_after_waits = 2
|
||||||
|
|
||||||
|
discord_bot.supervise_bot()
|
||||||
|
|
||||||
|
assert len(supervisor.built) == 2
|
||||||
|
|
||||||
|
def test_a_connection_that_lasted_resets_the_backoff(self, supervisor, monkeypatch):
|
||||||
|
"""Otherwise a bot that ran for a month and then dropped waits five
|
||||||
|
minutes before its first retry, on the strength of an incident that
|
||||||
|
is long over."""
|
||||||
|
clock = {'now': 0.0}
|
||||||
|
|
||||||
|
def fake_monotonic():
|
||||||
|
# Every run() call is deemed to have lasted longer than the
|
||||||
|
# reset threshold.
|
||||||
|
clock['now'] += discord_bot.BOT_RESTART_RESET_SECONDS + 1
|
||||||
|
return clock['now']
|
||||||
|
|
||||||
|
monkeypatch.setattr(discord_bot.time, 'monotonic', fake_monotonic)
|
||||||
|
supervisor.stop_after_waits = 3
|
||||||
|
|
||||||
|
discord_bot.supervise_bot()
|
||||||
|
|
||||||
|
assert supervisor.waits == [5, 5, 5], 'the back-off should not have grown'
|
||||||
|
|
||||||
|
|
||||||
|
class TestTheQueueSurvivesARestart:
|
||||||
|
def test_it_is_shared_by_every_instance(self, monkeypatch):
|
||||||
|
"""A queue living on the bot object would be discarded with it on
|
||||||
|
each restart, taking every pending notification along."""
|
||||||
|
monkeypatch.setattr(discord_bot, 'bot_instance', None)
|
||||||
|
first = discord_bot.get_bot()
|
||||||
|
monkeypatch.setattr(discord_bot, 'bot_instance', None)
|
||||||
|
second = discord_bot.get_bot()
|
||||||
|
|
||||||
|
assert first is not second
|
||||||
|
assert first.message_queue is second.message_queue
|
||||||
|
assert first.message_queue is discord_bot.message_queue
|
||||||
|
|||||||
Reference in New Issue
Block a user