«Письмо отправлено». Как у нас дважды за месяц молча ломалась почта

Человек регистрируется в нашем сервисе, вводит почту и видит «Письмо отправлено». Ждёт код. Код не приходит. Он нажимает «отправить ещё раз», снова ждёт, потом закрывает вкладку. Мы об этом не знаем: API ответил 200, ошибок в ответах нет.

Так было с 14 сентября по 1 октября, а потом ещё раз 5 октября. Причины разные, результат один: тишина. Ниже оба сбоя с конфигами, кодом и тем, что мы поменяли.

Как устроена отправка

API ──publish──> notifications.email.q ──> email-consumer ──SMTP:465──> Postfix ──> Gmail / Яндекс / Mail.ru
                          │
                          └── reject ──> notifications.dlx ──> notifications.dlq

Письмо не отправляется в момент нажатия кнопки. API публикует в RabbitMQ задачу: адрес, тему, HTML и message_id, случайный UUID. Очередь объявлена устойчивой и с обменником для недоставленных сообщений:

_email_queue = RabbitQueue(
    "notifications.email.q",
    durable=True,
    arguments={"x-dead-letter-exchange": "notifications.dlx"},
)

Задачи забирает отдельный процесс, email-consumer на FastStream. Он собирает письмо и отправляет его через aiosmtplib на наш Postfix, порт 465, сразу по TLS. Из message_id получается заголовок Message-ID: <uuid@example.ru>. Это пригодится дальше: по одному идентификатору письмо можно пройти от записи в базе до строки в журнале почтового сервера.

Правила отправки такие:

def _is_transient(error: Exception) -> bool:
    if isinstance(error, aiosmtplib.SMTPResponseException):
        return 400 <= error.code < 500
    return isinstance(
        error,
        aiosmtplib.SMTPConnectError
        | aiosmtplib.SMTPServerDisconnected
        | ConnectionError
        | TimeoutError,
    )

Каждый шаг письма пишется в таблицу notification_delivery_ledger. API после публикации добавляет строку queued, обработчик дописывает retrying, failed или accepted. Строки только добавляются. У каждой уникальный event_key вида <message_id>:<попытка>:<статус>, поэтому повторная обработка не плодит дублей. Адреса получателей в таблице нет, только его HMAC-SHA256.

Человеку API отвечает сразу после публикации. Значит, «Письмо отправлено» на экране означает ровно одно: задача легла в очередь.

Сбой первый: почта стучалась на сайт

Адрес почтового сервера в настройках прода выглядел так:

config:
  SMTP_HOST: example.ru
  SMTP_PORT: '465'
  SMTP_TLS: 'True'

Это строки из снимка helm get values от 23 августа. Мы держим такой снимок в репозитории, чтобы читать реальную конфигурацию прода без входа в кластер.

Корневой домен в роли SMTP-хоста работал, пока сайт был на WordPress и жил на одном сервере с почтой в Plesk. Корень вёл на этот сервер, порт 465 там был открыт. 5 августа мы проверяли отправку на dev ровно с такими настройками, письмо ушло.

В начале сентября мы перенесли сайт на свой сервер и переписали его на Next.js: статическую сборку отдаёт nginx. Корень домена теперь ведёт туда, а почта осталась в Plesk на mail.example.ru. Порт 465 на сервере сайта закрыт.

Дальше каждая попытка заканчивалась одинаково: SMTPConnectError, в тексте ошибки Connect call failed на порт 465. Отказ в соединении приходит мгновенно, поэтому три попытки укладывались примерно в пять секунд, после чего письмо получало статус failed.

Первая такая запись в журнале доставки появилась 14 сентября в 19:31 по Москве, последняя 1 октября в 08:48. Между ними 110 писем со статусом failed, среди них все коды подтверждения регистрации за это время. Переотправлять их потом было бессмысленно: код живёт 30 минут.

Почему первая ошибка датирована 14-м, а не днём переезда, мы до конца не восстановили. Логов обработчика за сентябрь нет: система их сбора, Loki, на момент разбора лежала, и сентябрьских записей в ней не оказалось. Всё, что мы знаем об этом сбое, взято из журнала доставки.

1 октября адрес в настройках прода поменяли на mail.example.ru и выпустили релиз v0.1.1. Письма пошли. Тот же адрес поправили в снимках настроек прода и стейджа и добавили тест, чтобы корень домена не вернулся туда случайно:

-  SMTP_HOST: example.ru
+  SMTP_HOST: mail.example.ru

def test_transactional_email_uses_the_mail_service_host() -> None:
    """The web apex points at the application host, not at the SMTP service."""

    for path in REFERENCE_VALUES:
        values = yaml.safe_load(path.read_text(encoding="utf-8"))
        env = values["config"]

        assert env["SMTP_HOST"] == "mail.example.ru", path.name
        assert str(env["SMTP_PORT"]) == "465", path.name
        assert str(env["SMTP_TLS"]).lower() == "true", path.name

Сбой второй: сертификат продлевался не там

5 октября письма снова перестали уходить. Последнее успешное письмо в проде ушло в 11:48 по Москве, первая ошибка случилась в 14:49. Обработчик стучался по правильному адресу, но TLS-рукопожатие не проходило:

SMTPConnectError: ... certificate has expired

Сертификат Let's Encrypt на почтовом сервере истёк 5 октября в 14:10 по Москве. Ошибка соединения по нашей классификации временная, так что каждое письмо прошло все три попытки. В журнале за сутки 12 ошибок, это четыре письма.

Сертификат выпускал и продлевал Plesk через расширение SSL It!. Сертификаты Let's Encrypt живут 90 дней, продлевают их примерно за 30 дней до конца срока. Plesk пытался каждый день начиная с 5 сентября, и каждый раз неудачно.

Сертификат был выписан на example.ru и *.example.ru. Подстановочное имя Let's Encrypt проверяет только через DNS-01, а корень проверялся через HTTP-01: Let's Encrypt запрашивает файл с одноразовым токеном по адресу

http://example.ru/.well-known/acme-challenge/<токен>

Корень, как и в первой истории, вёл на сервер сайта. Файла там нет, nginx отвечает 404, проверка проваливается. Месяц ежедневных отказов, о которых никто не узнал.

Сбой заметили на следующий день, когда проверяли, доходят ли письма новой регистрации. Сертификат перевыпустили в режиме «DNS для каждого имени»: теперь Let's Encrypt проверяет TXT-запись _acme-challenge.example.ru, и ему всё равно, на какую машину ведёт корень. Режим закреплён в параметрах домена (ext-sslit-preferredChallengeType = dns-01), поэтому автопродление пойдёт тем же путём. Новый сертификат действует до 4 января. Из пода обработчика проверили: TLS поднимается, AUTH отвечает 235.

Почта молчала почти 18 часов, не дошло четыре письма.

Одна и та же ловушка

Обе истории растут из одного места. Корень домена переехал на сервер сайта, а всё, что раньше считало корень почтовым, об этом не узнало. SMTP_HOST смотрел на корень. HTTP-01 проверял корень.

Тогда же нашёлся третий такой адрес. Почтовые тревоги нашего внутреннего мониторинга, Alertmanager, тоже смотрели на example.ru:465: smarthost собирался из того же значения SMTP_HOST. До беды не дошло, по почте система ещё не отправила ни одной тревоги. Но если бы отправила, тревога о сбое потерялась бы так же тихо, как письма. 22 октября адрес поменяли на mail.example.ru, и тестовая тревога дошла.

Почему никто не заметил

Ошибиться в настройке может кто угодно. Хуже, что две с лишним недели этого никто не видел. И здесь есть обидная деталь.

В начале августа мы уже ловили тихую пропажу писем. Тестировщица сказала, что письмо не пришло, а мы не могли ни подтвердить это, ни опровергнуть. Обработчик тогда выглядел примерно так:

# было (схематично)
try:
    await aiosmtplib.send(message, ...)
except Exception as error:
    logger.error(f"Error sending email: {error}")
# обработчик вернулся нормально: FastStream делает ACK, сообщение удалено

FastStream по умолчанию отклоняет сообщение, только если обработчик бросил исключение. А обработчик ловил любую ошибку, писал строчку в лог и завершался как ни в чём не бывало. Очередь получала подтверждение и удаляла письмо. Очередь недоставленных при этом была настроена, но попасть в неё было невозможно. Ни письма, ни следа, кроме одной строки в логе.

Тогда мы добавили повторы и проброс исключения после последней попытки. Комментарий в коде объясняет, зачем:

if not transient or attempt == _SEND_MAX_ATTEMPTS:
    # Re-raise instead of swallowing: returning normally here made
    # FastStream ACK the message, deleting it forever and leaving
    # the configured dead-letter queue permanently unreachable.
    raise

Сбой стал видимым. Видимым для того, кто смотрит в notifications.dlq. А смотреть было некому: у очереди недоставленных не было ни читателя, ни тревоги. Письмо попадало туда и лежало, никого не беспокоя.

Сверху легли ещё три вещи, каждая безобидная по отдельности. Три попытки с паузами 1 и 4 секунды отправляли в недоставленные всё, что не починилось за пять секунд. API отвечал 200, как только задача попадала в очередь. А журнал доставки, на который хочется опереться, хранит переходы, а не итог: «ушло» значит только, что среди строк письма есть accepted. Причём accepted пишется, когда наш Postfix ответил 250 и взял письмо. Лежит ли оно в ящике у человека, из журнала не видно.

Как мы проверили, что теперь доходит

Сначала журнал доставки. Письма, у которых есть failed и нет accepted, находятся одним запросом:

SELECT message_id,
       min(created_at) AS queued_at,
       max(error_code) FILTER (WHERE status = 'failed') AS error
FROM notification_delivery_ledger
WHERE channel = 'email'
GROUP BY message_id
HAVING bool_or(status = 'failed')
   AND NOT bool_or(status = 'accepted');

Потом журнал Postfix. Каждое письмо с отметкой accepted мы нашли там по Message-ID: сначала строка cleanup даёт внутренний идентификатор очереди Postfix, потом по нему видно, куда и с каким ответом ушло письмо.

grep -F 'message-id=<…@example.ru>' /var/log/maillog
grep -F '<queue id>' /var/log/maillog

После 6 октября все письма ушли адресатам: у Gmail, Яндекса и Mail.ru статус sent, ни одного deferred.

Заодно проверили, доверяют ли нашей почте. SPF, DKIM и DMARC проходят, обратная запись PTR совпадает с именем сервера, в чёрных списках домена нет. Одно мы так и не проверили: попадает ли письмо во «Входящие» или в спам.

Что поменяли в самой почте

Один экран вместо пяти мест

Разбирая обе истории, мы поняли, что дело не в одной неверной строке. Сигналы о сбое существовали, но жили в разных местах: журнал доставки в базе, очередь в RabbitMQ, логи обработчика в Loki, сертификат в Plesk, тревоги в Alertmanager. Чтобы увидеть проблему, нужно было заранее знать, куда смотреть. А если знаешь, куда смотреть, проблема уже найдена.

Поэтому мы свели состояние инфраструктуры на один экран мониторинга. На нём:

Всё найденное сводится в один список проблем с приоритетами от P0 до P3. Вместо пяти мест, куда надо заглянуть, остаётся один вопрос: есть ли сейчас что-то срочное.

Почта встроена в общую картину

Отдельной страницы «почта» на этом экране нет, и это сделано намеренно. Почта проверяется так же, как сайт или база.

Проверка берёт тот же SMTP_HOST:SMTP_PORT, по которому ходит обработчик писем. Она подключается к серверу, проходит TLS-рукопожатие и читает сертификат. Если соединение не открылось или сертификат не принят, появляется проблема P1 с прямым текстом: сертификат почтового сервера не проходит проверку, письма могут не уходить. Срок сертификата отслеживается отдельно: за 30 дней до конца это P2, за 14 дней уже P1. Если имя почтового сервера не находится в DNS, это тоже P1.

Очереди видны там же. У notifications.email.q внимание включается с 50 писем, тревога с 500 или когда у очереди пропал подписчик, то есть упал сам обработчик. У notifications.dlq внимание включается с первого же недоставленного письма.

Что было бы с нашими сбоями, если бы такой экран уже работал. В сентябре проверка постучалась бы на example.ru:465 вслед за обработчиком, не прошла бы рукопожатие и подняла P1. Сбой был бы виден через несколько проверок, а не через две с половиной недели. В октябре экран показал бы «сертификат почты истекает через 30 дней» ещё 5 сентября, в тот же день, когда начались неудачные продления.

Инцидент вместо строчки в логе

Сигнал, который держится, превращается в инцидент: P0 открывается сразу, P1 после трёх проверок подряд, P2 после десяти. У инцидента есть открытие, усиление и решение, а в истории видно, сколько он длился. Об открытии и решении инцидента сообщение уходит в Telegram-чат администраторов, об усилении для P0 и P1, с паузой не меньше 30 минут, чтобы чат не превратился в шум.

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

Что из этого следует

«Письмо отправлено» на экране значит одно: задача легла в очередь. Дошло ли письмо, видно только в конце цепочки, и смотреть надо туда.

Очередь недоставленных без сигнала мало чем лучше удаления. Письма в ней не исчезают, но и никто о них не узнаёт. У такой очереди должен быть кто-то, кого она будит.

Сигналы, разбросанные по пяти системам, почти не отличаются от отсутствия сигналов. Проверки почты должны жить там же, где проверки всего остального, и смотреть туда же, куда ходит сама почта.

После переезда корневого домена стоит найти всё, что на него ссылалось: адреса почты, проверки сертификатов, мониторинг. У нас таких мест нашлось три, и два из них сработали как мины замедленного действия.

Одну привычку экран не заменяет: раз в день и после каждой выкладки отправлять настоящее письмо на свой ящик и смотреть, пришло ли оно. Проверка сертификата у нас теперь встроена в общий экран мониторинга. Если такого экрана у вас нет, хватит одной команды:

openssl s_client -connect mail.example.ru:465 -servername mail.example.ru </dev/null 2>/dev/null \
  | openssl x509 -noout -enddate