Платёжный шлюз ответил 200 и не провёл платёж: двое суток сверки

MAATRIX

Клиент присылает скриншот: деньги списаны, банк подтвердил, а в личном кабинете заказ всё ещё «ожидает оплаты». Первая мысль — разовый глюк, обновит страницу и всё появится. Через час таких скриншотов уже пять, а платёжный шлюз в своём логе показывает ровный ряд 200 OK на каждый вебхук. Разбираем инцидент, где симптом маскировался под пользовательскую ошибку два дня, а причина оказалась в одной строке валидации.

Что произошло: платёж прошёл, а заказ остался неоплаченным

Схема у большинства интернет-магазинов и SaaS одинаковая: пользователь платит на стороне шлюза (не важно, ЮKassa это, CloudPayments, Stripe или локальный эквайринг), шлюз списывает деньги и присылает на ваш сервер вебхук с уведомлением об успешном платеже. Ваш бэкенд принимает вебхук, помечает заказ оплаченным, открывает доступ или запускает отгрузку. Если вебхук не пришёл или обработался с ошибкой — заказ так и остаётся «неоплаченным», хотя деньги уже у вас.

В нашем случае за первые сутки инцидента набралось около полутора десятков подобных обращений — не масса, но и не единичный случай, чтобы списать на «пользователь ошибся». Общее у всех обращений: оплата картой через один и тот же способ подключения (recurring/сохранённая карта), время — вечер и ночь, когда дежурный смотрит только красные алерты, а «жёлтых» предупреждений в логах никто не читает.

Первая ошибка была управленческой, а не технической: поддержка полдня отрабатывала тикеты как «пользователь перепутал заказы» — потому что в мониторинге не было ни одного триггера, который бы сказал «деньги идут мимо». Все системные метрики — CPU, память, время ответа API, доступность сайта — были зелёными. Важно не путать «сервис отвечает» и «сервис делает то, что должен»: подробнее об этой ловушке — в статье про антипаттерн мониторинга, который никто не смотрит.

Что показывали логи и метрики в первые часы

Первым делом подняли access-логи nginx перед вебхук-эндпоинтом:

195.xx.xx.xx - - [28/Aug/2026:22:14:07 +0000] "POST /api/webhooks/payment HTTP/1.1" 200 18 "-" "PaymentGateway-Webhook/1.4"
195.xx.xx.xx - - [28/Aug/2026:22:14:07 +0000] "POST /api/webhooks/payment HTTP/1.1" 200 18 "-" "PaymentGateway-Webhook/1.4"
195.xx.xx.xx - - [28/Aug/2026:22:31:52 +0000] "POST /api/webhooks/payment HTTP/1.1" 200 18 "-" "PaymentGateway-Webhook/1.4"

Всё чисто: запросы доходят, ответ — 200, без таймаутов и разрывов соединения. Это первое, что сбило с толку: если бы шлюз получал 5xx или таймаут, он бы честно ретраил доставку по своей политике (обычно несколько попыток с нарастающим интервалом в течение нескольких часов), и в конце концов заказ бы «дошёл». А тут — 200 с первого раза, значит, с точки зрения шлюза доставка вебхука состоялась и повторов не будет.

Дальше посмотрели прикладные логи бэкенда на уровне INFO — тот, что уходит в общий агрегатор логов и виден в дашборде:

INFO 2026-08-28T22:14:07Z webhook.received event=payment.succeeded order_id=None
INFO 2026-08-28T22:14:07Z webhook.enqueued queue=payments:incoming

Заказ обрабатывается асинхронно: вебхук-хендлер разбирает тело запроса ровно настолько, чтобы понять тип события, кладёт сырой payload в очередь (у нас это был Redis-лист через LPUSH) и сразу отвечает 200 — чтобы не держать шлюз в ожидании, пока фоновый воркер сходит в базу. Дальше уже отдельный процесс-воркер вычитывает очередь и обновляет статус заказа.

Проблема в том, что на уровне INFO не видно, что происходит с сообщением дальше — воркер логировал ошибки уровнем DEBUG, а DEBUG в проде был выключен ещё полгода назад ради экономии места на диске. То есть система молчала не потому, что всё было хорошо, а потому что именно то место, где всё ломалось, было единственным, откуда лог не долетал до дежурного. Это отдельная и очень частая грабля: подробно про настройку алертов, которые реально доходят до людей, а не тонут в невидимом канале — в статье про алерты в Telegram на сервере.

Гипотезы, которые отбросили

Прежде чем добраться до причины, отработали четыре версии — все правдоподобные, все мимо.

Версия 1: сеть режет часть запросов между шлюзом и сервером. Проверили firewall (ufw/iptables) на предмет случайного дропа по IP шлюза, посмотрели на графике сетевых интерфейсов всплески потерянных пакетов за нужные часы. Ничего — ни одного отброшенного соединения, все TCP-хендшейки завершались штатно, доставка вебхуков подтверждена логами шлюза (в личном кабинете провайдера видно статус доставки каждого события, и там тоже стояло «доставлено, 200»).

Версия 2: пул соединений с базой исчерпан, запись не проходит. Подняли логи PostgreSQL за окно инцидента — ни одной ошибки too many connections, ни одного лога о превышении statement_timeout. pg_stat_activity в моменте показывал обычную нагрузку. Версию закрыли: если бы дело было в БД, ошибки были бы видны на уровне самой БД, а не только в приложении.

Версия 3: гонка между двумя вебхуками по одному заказу. У некоторых платёжных шлюзов при подтверждении recurring-платежа может прийти два события подряд (например, payment.waiting_for_capture и payment.succeeded), и если обработка не идемпотентна, второе событие может затереть или проигнорировать первое. Проверили по event_id и idempotency_key в логах — для всех проблемных заказов пришло ровно одно событие payment.succeeded, дублей не было. Версия тоже не подтвердилась.

Версия 4: пользователь закрыл вкладку до завершения оплаты, и это вообще не баг, а невнимательность клиента. Самая соблазнительная версия, потому что снимает вопрос с разработчиков. Её закрыли быстрее всего: выгрузка из личного кабинета шлюза по датам показала, что деньги реально списаны и транзакции у провайдера в статусе «успешно завершена» — то есть с точки зрения банка и шлюза платёж состоялся полностью, вопрос был только в том, почему это событие не долетело живым до нашей базы.

Как нашли реальную причину

Раз доставка на уровне HTTP была в порядке, а в БД ничего не билось об ошибку, оставалось одно место, куда ещё не заглядывали всерьёз, — сам воркер, который разбирает сообщения из очереди. Временно включили DEBUG-логирование только для этого процесса (через переменную окружения и перезапуск сервиса systemd, без общего понижения уровня логов на всём бэкенде) и подождали следующего инцидента — благо, повторялось стабильно несколько раз в день.

Через пару часов в логе появилось то, чего не хватало:

DEBUG 2026-08-28T23:02:14Z worker.process_failed order_ref=8841
Traceback (most recent call last):
  File "worker.py", line 47, in handle_payment_event
    amount = Decimal(payload["amount"]) / 100
TypeError: conversion from dict to Decimal is not supported

Вот и вся причина: поле amount в вебхуке раньше приходило как число в минимальных единицах валюты (копейки/центы), а в этот раз пришло как объект {"value": "1490.00", "currency": "RUB"}. Шлюз в рамках плановой доработки — поддержки мультивалютных платежей — начал постепенно переводить часть маршрутов оплаты на новый формат суммы, о чём было написано в их changelog за пару недель до инцидента. Раскатка шла не на весь трафик сразу, а по конкретным способам оплаты и банкам-эквайерам — этим и объясняется, почему ломались не все платежи подряд, а только часть: новый формат прилетал именно на recurring-платежи через один из подключённых эквайеров, и выглядело это как случайная, невоспроизводимая проблема, пока не собралась выборка достаточного размера.

Дальше — самое неприятное в этой истории. Код воркера был обёрнут в широкий try/except, который ловил любое исключение, писал его в лог уровнем DEBUG и переходил к следующему сообщению:

while True:
    raw = redis_client.brpop("payments:incoming", timeout=5)
    if not raw:
        continue
    try:
        handle_payment_event(json.loads(raw[1]))
    except Exception as exc:
        logger.debug("worker.process_failed order_ref=%s", extract_ref(raw), exc_info=True)
        # сообщение уже вычитано из очереди (BRPOP) — повторной обработки не будет
        continue

BRPOP в Redis атомарно вынимает элемент из списка — если обработка после этого падает, сообщение уже потеряно, автоматического повтора не предусмотрено. А поскольку HTTP-эндпоинт вебхука уже ответил шлюзу 200 OK в момент постановки в очередь, а не в момент завершения обработки, у шлюза тоже не было повода что-то повторять — с его стороны доставка состоялась. Получилась связка из трёх по отдельности разумных решений (быстрый ответ шлюзу, асинхронная обработка, не ронять воркер на одном плохом сообщении), которые вместе создали дыру, в которую тихо утекали платежи.

Сверка: как за двое суток посчитали ущерб и закрыли дыры

Первым делом остановили кровотечение — задеплоили патч, который делает парсинг суммы терпимым к обоим форматам:

def parse_amount(raw_amount):
    if isinstance(raw_amount, dict):
        return Decimal(raw_amount["value"])
    return Decimal(raw_amount) / 100

Это закрыло появление новых пропусков, но не решало вопрос уже потерянных платежей за предыдущие часы — а часть из них уходила ещё до того, как появились первые жалобы. Ручной разбор по тикетам поддержки такую полноту гарантировать не мог: люди пишут не всегда сразу, а некоторые вообще не пишут, если сумма небольшая.

Поэтому подняли полноценную сверку между двумя источниками правды: списком успешных транзакций у шлюза (через их API выгрузки платежей за период) и локальной таблицей заказов. Скрипт на Python выгружал транзакции провайдера за последние 48 часов постранично, сохранял во временную таблицу и искал расхождения обычным LEFT JOIN:

SELECT g.transaction_id, g.amount, g.paid_at
FROM gateway_transactions_import g
LEFT JOIN orders o ON o.transaction_id = g.transaction_id
WHERE o.id IS NULL
   OR o.status <> 'paid';

За два дня набора данных сверка нашла заметно больше расхождений, чем пришло тикетов в поддержку, — то есть часть пострадавших клиентов вообще не обратились, просто решили, что оплата «зависла», и ушли. Каждую строку из выгрузки обработали вручную: заказ помечали оплаченным задним числом, открывали доступ или запускали отгрузку, клиентам отправили короткое извинение с объяснением, что платёж был подтверждён с задержкой не по их вине.

Сама сверка заняла те самые «двое суток» не потому, что запрос выполнялся долго, а по трём причинам: API шлюза отдавал транзакции постранично с ограничением по частоте запросов, и на скачивание всего периода ушло несколько часов; часть расхождений оказались легитимными — отменённые заказы, возвраты, тестовые платежи — их пришлось вручную отсеивать от реальных потерянных вебхуков; а итоговый список и восстановление доступа клиентам согласовывали с поддержкой и бухгалтерией, чтобы не открыть доступ по ошибке ещё раз.

Что изменили в архитектуре после инцидента

Разбор такого рода имеет смысл только если он меняет систему, а не только латает конкретный баг. Изменили четыре вещи.

1. Вебхук отвечает 200 только после реальной фиксации платежа. Отказались от схемы «прими и сразу отвечай, обработаешь потом» в пользу синхронной записи факта платежа в БД прямо в теле хендлера (быстрая операция — вставка строки в таблицу событий), а уже тяжёлые побочные действия (отправка писем, начисление бонусов, интеграции со складом) вынесены в отдельную очередь через паттерн outbox — то есть запись о событии и запись о необходимости последующей обработки сохраняются в одной транзакции с БД. Если запись в БД не удалась — эндпоинт честно отвечает 500, и шлюз повторит доставку по своей политике ретраев вместо того, чтобы считать вопрос закрытым.

2. Любое исключение в обработке платёжного события — это ошибка, а не строчка в DEBUG. Настроили отправку трейсбеков из воркера и вебхук-хендлера в Sentry с уровнем ERROR и алертом в дежурный канал при любом исключении на пути обработки платежа — без фильтров «раз в час» и без права упасть тихо. Как поднять и настроить такой трекинг ошибок — отдельно разобрано в статье про настройку Sentry для мониторинга ошибок.

3. Парсинг внешних payload'ов стал терпимым к неизвестным полям и версионируемым по формату. Строгая схема, которая падает на любом отклонении от ожидаемой структуры, хороша для внутренних API, но опасна для интеграций с третьей стороной, которая имеет право менять формат без предупреждения (даже если формально предупредила в changelog за две недели). Добавили явную проверку формата суммы с фолбэком и юнит-тест на оба варианта payload — старый и новый.

4. Сверка стала автоматической и регулярной, а не аварийной мерой постфактум. Тот же скрипт сравнения транзакций шлюза с локальными заказами теперь гоняется по cron каждый час и обычным явлением себя не оправдал — зато при повторном сбое расхождение будет замечено в течение часа, а не за счёт скриншотов от расстроенных клиентов:

0 * * * * /usr/bin/python3 /opt/app/scripts/reconcile_payments.py --hours 2 >> /var/log/app/reconcile.log 2>&1

Если расхождений больше нуля — скрипт сам шлёт сообщение в дежурный чат с перечнем transaction_id, а не просто пишет в лог, который никто не читает до следующего расследования.

Частые вопросы