Небольшой разбор бага, который жил у меня в проде несколько недель и вылез наружу самым неприятным способом — на живых пользователях.
ЧТО СЛУЧИЛОСЬ
В боте есть цепочка уведомлений: за 6 часов до конца пробного периода, за 3 часа, за час. Плюс отдельные напоминания о неоплаченном счёте и цепочка возврата ушедших клиентов. Фоновая задача раз в 5 минут выбирает подходящих пользователей и рассылает сообщения.
Однажды днём один человек получил уведомление «осталось 24 часа» четыре раза подряд. Ещё у троих — по четыре дубля другого касания. В тот день я трижды перезапускал бота, выкатывая правки.
ПОЧЕМУ ТАК ВЫШЛО
Отметка «этому уже отправляли» хранилась в памяти процесса:
class RetentionService:
def init(self):
self._sent = set()
async def notify(self, user):
key = (user.id, "trial_6h")
if key in self._sent:
return
await bot.send_message(user.id, TEXT)
self._sent.add(key)
Пока процесс живёт — всё честно. Но при рестарте set пустой, а окно отправки ещё открыто: пользователь всё ещё попадает в выборку «осталось 5-6 часов». Три перезапуска за час = три дубля плюс исходная отправка.
Отдельная подлость в том, что баг невидим в разработке. Локально бота не перезапускают в момент открытого окна уведомлений, и тесты его не ловят: юнит-тест поднимает свежий объект сервиса, а именно в этом и проблема.
ПОЧЕМУ ФАЙЛ НА ДИСКЕ ТОЖЕ НЕ РЕШЕНИЕ
Первая мысль — сериализовать set в файл. Не подходит: контейнер эфемерный, диск может не пережить пересоздание, а при нескольких воркерах начнётся гонка за один файл. Состояние доставки — это данные, а данные живут в базе.
КАК СДЕЛАНО СЕЙЧАС
Факт отправки пишется в таблицу аудита, а проверка идёт по ней:
async def already_sent(session, user_id, window, period_end) -> bool:
target = f"{user_id}:{int(period_end.timestamp())}"
stmt = select(AuditLog.id).where(
AuditLog.action == f"retention_{window}",
AuditLog.target_id == target,
).limit(1)
return (await session.execute(stmt)).first() is not None
Ключевой момент здесь — состав target_id. Если писать только user_id, то человек, продливший подписку, больше никогда не получит уведомлений: отметка-то стоит. Поэтому в ключ входит момент окончания текущего периода. Продлился — момент сменился, ключ новый, цепочка снова работает.
По сути это ключ идемпотентности: не «кому отправляли», а «кому отправляли в рамках какого цикла».
ГОНКИ
Если воркеров несколько, проверка и запись не атомарны: две задачи одновременно получают «не отправляли» и шлют по сообщению. Лечится уникальным индексом по (action, target_id) и вставкой с ON CONFLICT DO NOTHING — отправляем только если запись реально создалась:
stmt = insert(AuditLog).values(
action=f"retention_{window}",
target_id=target,
).on_conflict_do_nothing(index_elements=["action", "target_id"])
result = await session.execute(stmt)
if result.rowcount == 0:
return # кто-то уже занял слот
await bot.send_message(user_id, TEXT)
Порядок важен: сначала занимаем слот в базе, потом отправляем. При обратном порядке падение между отправкой и записью снова даст дубль.
ЕЩЁ ОДНА ДЕТАЛЬ — ОКНА
Изначально окна уведомлений стояли впритык: 6ч, 3ч, 1ч. Цикл ходит раз в 5 минут, и при перезапуске узкое окно можно просто проскочить — человек не получит уведомление вовсе. Сейчас окна с запасом и с разрывами между ними: 6.5–5.0ч, 3.5–2.2ч, 1.2–0.4ч. Разрывы нужны, чтобы два касания не пришли подряд одно за другим.
ВЫВОДЫ
1. Любое «уже сделано» для внешних эффектов — в базу, не в память процесса.
2. Ключ идемпотентности должен включать не только субъекта, но и цикл, иначе повторное действие никогда не сработает.
3. Слот занимаем до отправки, а не после.
4. Окна фоновых задач делайте шире периода их запуска, иначе рестарт съест событие.
Баг стоил мне четырёх сообщений одному человеку и неприятного разговора с ним. Дёшево отделался — при большей базе это была бы массовая рассылка дублей.
ЧТО СЛУЧИЛОСЬ
В боте есть цепочка уведомлений: за 6 часов до конца пробного периода, за 3 часа, за час. Плюс отдельные напоминания о неоплаченном счёте и цепочка возврата ушедших клиентов. Фоновая задача раз в 5 минут выбирает подходящих пользователей и рассылает сообщения.
Однажды днём один человек получил уведомление «осталось 24 часа» четыре раза подряд. Ещё у троих — по четыре дубля другого касания. В тот день я трижды перезапускал бота, выкатывая правки.
ПОЧЕМУ ТАК ВЫШЛО
Отметка «этому уже отправляли» хранилась в памяти процесса:
class RetentionService:
def init(self):
self._sent = set()
async def notify(self, user):
key = (user.id, "trial_6h")
if key in self._sent:
return
await bot.send_message(user.id, TEXT)
self._sent.add(key)
Пока процесс живёт — всё честно. Но при рестарте set пустой, а окно отправки ещё открыто: пользователь всё ещё попадает в выборку «осталось 5-6 часов». Три перезапуска за час = три дубля плюс исходная отправка.
Отдельная подлость в том, что баг невидим в разработке. Локально бота не перезапускают в момент открытого окна уведомлений, и тесты его не ловят: юнит-тест поднимает свежий объект сервиса, а именно в этом и проблема.
ПОЧЕМУ ФАЙЛ НА ДИСКЕ ТОЖЕ НЕ РЕШЕНИЕ
Первая мысль — сериализовать set в файл. Не подходит: контейнер эфемерный, диск может не пережить пересоздание, а при нескольких воркерах начнётся гонка за один файл. Состояние доставки — это данные, а данные живут в базе.
КАК СДЕЛАНО СЕЙЧАС
Факт отправки пишется в таблицу аудита, а проверка идёт по ней:
async def already_sent(session, user_id, window, period_end) -> bool:
target = f"{user_id}:{int(period_end.timestamp())}"
stmt = select(AuditLog.id).where(
AuditLog.action == f"retention_{window}",
AuditLog.target_id == target,
).limit(1)
return (await session.execute(stmt)).first() is not None
Ключевой момент здесь — состав target_id. Если писать только user_id, то человек, продливший подписку, больше никогда не получит уведомлений: отметка-то стоит. Поэтому в ключ входит момент окончания текущего периода. Продлился — момент сменился, ключ новый, цепочка снова работает.
По сути это ключ идемпотентности: не «кому отправляли», а «кому отправляли в рамках какого цикла».
ГОНКИ
Если воркеров несколько, проверка и запись не атомарны: две задачи одновременно получают «не отправляли» и шлют по сообщению. Лечится уникальным индексом по (action, target_id) и вставкой с ON CONFLICT DO NOTHING — отправляем только если запись реально создалась:
stmt = insert(AuditLog).values(
action=f"retention_{window}",
target_id=target,
).on_conflict_do_nothing(index_elements=["action", "target_id"])
result = await session.execute(stmt)
if result.rowcount == 0:
return # кто-то уже занял слот
await bot.send_message(user_id, TEXT)
Порядок важен: сначала занимаем слот в базе, потом отправляем. При обратном порядке падение между отправкой и записью снова даст дубль.
ЕЩЁ ОДНА ДЕТАЛЬ — ОКНА
Изначально окна уведомлений стояли впритык: 6ч, 3ч, 1ч. Цикл ходит раз в 5 минут, и при перезапуске узкое окно можно просто проскочить — человек не получит уведомление вовсе. Сейчас окна с запасом и с разрывами между ними: 6.5–5.0ч, 3.5–2.2ч, 1.2–0.4ч. Разрывы нужны, чтобы два касания не пришли подряд одно за другим.
ВЫВОДЫ
1. Любое «уже сделано» для внешних эффектов — в базу, не в память процесса.
2. Ключ идемпотентности должен включать не только субъекта, но и цикл, иначе повторное действие никогда не сработает.
3. Слот занимаем до отправки, а не после.
4. Окна фоновых задач делайте шире периода их запуска, иначе рестарт съест событие.
Баг стоил мне четырёх сообщений одному человеку и неприятного разговора с ним. Дёшево отделался — при большей базе это была бы массовая рассылка дублей.
Последнее редактирование:
