По какой-то причине мы не можем отправить электронное письмо большего размера одному из наших клиентов. Небольшие электронные письма - это нормально, но даже сообщение с вложением 1 МБ не доставляется в течение нескольких часов - журналы Postfix продолжают заполняться status=deferred (conversation with customer***[IP***] timed out while sending message body), но в конечном итоге сообщения отправляются.
Клиент использует «Microsoft ESMTP MAIL Service, версия: 6.0.3790.3959» (проверено с помощью telnet на порт 25), хотя я не уверен, что это действительно ошибка программного обеспечения получателя. Мы можем без проблем отправлять электронную почту практически везде. Заказчик подтвердил, что у него нет такой проблемы с другими людьми, отправляющими ему почту. Кажется, зависает только почта с нашего сервера.
Я пробовал снизить значение MTU нашего исходящего интерфейса до 1000 и даже 500. В других местах, например этот или этот показать, что есть редкая проблема, но без решений или подтверждений.
Ниже представлен журнал Postfix типичного процесса отправки сообщения этому клиенту. (Адреса электронной почты заменены на ***, почтовый сервер клиента с customer*** и ip***)
Aug 18 15:41:28 gozilla postfix/cleanup[14751]: F0DB414080: message-id=<***>
Aug 18 15:41:28 gozilla postfix/qmgr[21922]: F0DB414080: from=<***>, size=1671905, nrcpt=1 (queue active)
Aug 18 15:44:44 gozilla postfix/qmgr[14985]: F0DB414080: skipped, still being delivered
Aug 18 15:44:45 gozilla postfix/qmgr[15132]: F0DB414080: skipped, still being delivered
Aug 18 15:44:45 gozilla postfix/qmgr[15242]: F0DB414080: skipped, still being delivered
Aug 18 15:44:47 gozilla postfix/smtp[14752]: F0DB414080: to=<***>, relay=customer***[IP***], delay=199, delays=0.64/0/0.68/198, dsn=4.4.2, status=deferred (conversation with customer***[IP***] timed out while sending message body)
Aug 18 15:46:44 gozilla postfix/qmgr[15242]: F0DB414080: from=<***>, size=1671905, nrcpt=1 (queue active)
Aug 18 15:50:01 gozilla postfix/smtp[15555]: F0DB414080: to=<***>, relay=customer***[IP***]:25, delay=514, delays=317/0.01/0.17/196, dsn=4.4.2, status=deferred (conversation with customer***[IP***] timed out while sending message body)
Aug 18 15:52:52 gozilla postfix/qmgr[15242]: F0DB414080: from=<***>, size=1671905, nrcpt=1 (queue active)
Aug 18 15:56:35 gozilla postfix/smtp[15872]: F0DB414080: to=<***>, relay=customer***[IP***]:25, delay=908, delays=685/0.01/0.16/222, dsn=4.4.2, status=deferred (conversation with customer***[IP***] timed out while sending message body)
Aug 18 16:14:45 gozilla postfix/qmgr[15242]: F0DB414080: from=<***>, size=1671905, nrcpt=1 (queue active)
Aug 18 16:18:18 gozilla postfix/smtp[17065]: F0DB414080: to=<***>, relay=customer***[IP***]:25, delay=2210, delays=1997/0/0.17/213, dsn=4.4.2, status=deferred (conversation with customer***[IP***] timed out while sending message body)
Aug 18 16:23:22 gozilla postfix/qmgr[17635]: F0DB414080: from=<***>, size=1671905, nrcpt=1 (queue active)
Aug 18 16:27:23 gozilla postfix/smtp[17646]: F0DB414080: to=<***>, relay=customer***[IP***]:25, delay=2755, delays=2515/0.01/0.21/240, dsn=4.4.2, status=deferred (conversation with customer***[IP***] timed out while sending message body)
--- cut out more lines like this ---
Aug 18 19:56:17 gozilla postfix/qmgr[18145]: F0DB414080: from=<***>, size=1671905, nrcpt=1 (queue active)
Aug 18 19:59:31 gozilla postfix/smtp[26730]: F0DB414080: to=<***>, relay=customer***[IP***]:25, delay=15484, delays=15289/0.01/0.2/194, dsn=4.4.2, status=deferred (conversation with customer***[IP***] timed out while sending message body)
Aug 18 22:21:17 gozilla postfix/qmgr[18145]: F0DB414080: from=<***>, size=1671905, nrcpt=1 (queue active)
Aug 18 22:26:01 gozilla postfix/smtp[32493]: F0DB414080: to=<***>, relay=customer***[IP***]:25, delay=24274, delays=23989/0.01/0.37/284, dsn=2.6.0, status=sent (250 2.6.0 <***> Queued mail for delivery)
Aug 18 22:26:01 gozilla postfix/qmgr[18145]: F0DB414080: removed
О, мальчик, я люблю эти серверы. Почти всегда они выполняют сканирование тел сообщений на основе содержимого, а затем отправляют не-200 ответов на команду DATA, если им не нравится содержимое. В принципе, это нормально, но когда у вас есть какой-то дрянной мусор, работающий под управлением Exchange, и чрезмерная трата проприетарного дискового пространства на сканирование, машина работает как патока, а у всех остальных время ожидания.
Да, теоретически это может быть проблема MTU, как вы предложили, но на практике это довольно маловероятно - если вы можете передать сообщение размером 2000 байт, это опровергает эту теорию (а сообщений меньше 2000 не так много. байтов, включая заголовки). Tcpdump на вашей стороне может подтвердить это - если это проблема уровня TCP, то вы увидите попытки с вашей стороны повторно передать полноразмерный пакет; если это удаленная проблема с медленным MTA, то повторных передач не будет, и точка остановки наступит, когда ваш конец отправит закрытие ".".
Учитывая, что дальний конец кажется невежественным ("все еще нет проблем "мой видный за спиной), я бы просто увеличил тайм-аут Postfix до некоторой значительно большей цифры и оставил все как есть. Три настройки, которые вы хотите изучить, это smtp_data_done_timeout, smtp_data_xfer_timeout, и smtp_data_init_timeout (примерно в таком порядке важности). Как видите, настройки по умолчанию очень щедры, поэтому необходимость их увеличения действительно указывает на то, насколько тяжелым является дальний конец.