none
Непонятные задержки при отправке писем по smtp RRS feed

  • Вопрос

  • Здравствуйте. 

    Периодически наблюдаю проблемы с долгой отправкой писем через smtp.

    Клиентом из внутренней сети отправляется письмо на внутренний интерфейс сервера через smtp без авторизации. Письмо отправляется секунд 40-60. Если после этого отправить еще письмо, то уходит быстро. Через несколько минут (вроде 10-15) ситуация повторяется. Обе роли на одном сервере, сервер виртульный.

    Вот логи:

    FrontEnd Receive:

    "2013-10-05T13:03:49.727Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,0,192.168.20.30:25,192.168.3.106:1413,+,,"
    "2013-10-05T13:03:49.727Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,1,192.168.20.30:25,192.168.3.106:1413,*,SMTPSubmit SMTPAcceptAnySender SMTPAcceptAuthoritativeDomainSender AcceptRoutingHeaders,Set Session Permissions"
    "2013-10-05T13:03:49.727Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,2,192.168.20.30:25,192.168.3.106:1413,>,220 hello,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,3,192.168.20.30:25,192.168.3.106:1413,<,EHLO [127.0.0.1],"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,4,192.168.20.30:25,192.168.3.106:1413,>,250-exch.domain.ru Hello [192.168.3.106],"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,5,192.168.20.30:25,192.168.3.106:1413,>,250-SIZE 37748736,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,6,192.168.20.30:25,192.168.3.106:1413,>,250-PIPELINING,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,7,192.168.20.30:25,192.168.3.106:1413,>,250-DSN,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,8,192.168.20.30:25,192.168.3.106:1413,>,250-ENHANCEDSTATUSCODES,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,9,192.168.20.30:25,192.168.3.106:1413,>,250-STARTTLS,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,10,192.168.20.30:25,192.168.3.106:1413,>,250-X-ANONYMOUSTLS,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,11,192.168.20.30:25,192.168.3.106:1413,>,250-AUTH,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,12,192.168.20.30:25,192.168.3.106:1413,>,250-X-EXPS GSSAPI NTLM,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,13,192.168.20.30:25,192.168.3.106:1413,>,250-8BITMIME,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,14,192.168.20.30:25,192.168.3.106:1413,>,250-BINARYMIME,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,15,192.168.20.30:25,192.168.3.106:1413,>,250-CHUNKING,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,16,192.168.20.30:25,192.168.3.106:1413,>,250 XRDST,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,17,192.168.20.30:25,192.168.3.106:1413,<,MAIL FROM:<user@domain.ru> SIZE=363,"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,18,192.168.20.30:25,192.168.3.106:1413,*,08D08FCA2DD6E8FC;2013-10-05T13:03:49.727Z;1,receiving message"
    "2013-10-05T13:03:49.743Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,19,192.168.20.30:25,192.168.3.106:1413,>,250 2.1.0 Sender OK,"
    "2013-10-05T13:03:49.774Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,20,192.168.20.30:25,192.168.3.106:1413,<,RCPT TO:<user@domain.ru>,"
    "2013-10-05T13:05:08.570Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,21,192.168.20.30:25,192.168.3.106:1413,>,250 2.1.5 Recipient OK,"
    "2013-10-05T13:05:08.570Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,22,192.168.20.30:25,192.168.3.106:1413,<,DATA,"
    "2013-10-05T13:05:08.570Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,23,192.168.20.30:25,192.168.3.106:1413,>,354 Start mail input; end with <CRLF>.<CRLF>,"
    "2013-10-05T13:05:08.585Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,24,192.168.20.30:25,192.168.3.106:1413,*,,Proxy destination(s) obtained from OnProxyInboundMessage event"
    "2013-10-05T13:05:26.775Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,25,192.168.20.30:25,192.168.3.106:1413,>,250 2.6.0 <52500E34.7080402@domain.ru> [InternalId=1773821493262] Queued mail for delivery,"
    "2013-10-05T13:05:26.775Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,26,192.168.20.30:25,192.168.3.106:1413,<,QUIT,"
    "2013-10-05T13:05:26.775Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,27,192.168.20.30:25,192.168.3.106:1413,>,221 2.0.0 Service closing transmission channel,"
    "2013-10-05T13:05:26.775Z,exch\FrontEnd From Intranet,08D08FCA2DD6E8FC,28,192.168.20.30:25,192.168.3.106:1413,-,,Local"

    FronEnd Send:

    "2013-10-05T13:02:09.950Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,56,192.168.20.30:41621,192.168.20.30:2525,<,250 2.6.0 <201310051301.r95D1IIO023747@xx.xx.ru> [InternalId=1773821493258] Queued mail for delivery,"
    "2013-10-05T13:05:26.447Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,57,192.168.20.30:41621,192.168.20.30:2525,*,,Proxying inbound session with session id 08D08FCA2DD6E8FC"
    "2013-10-05T13:05:26.447Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,58,192.168.20.30:41621,192.168.20.30:2525,>,RSET,"
    "2013-10-05T13:05:26.447Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,59,192.168.20.30:41621,192.168.20.30:2525,<,250 2.0.0 Resetting,"
    "2013-10-05T13:05:26.447Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,60,192.168.20.30:41621,192.168.20.30:2525,>,XPROXYFROM SID=08D08FCA2DD6E8FC IP=192.168.3.106 PORT=1413 DOMAIN=[127.0.0.1] SEQNUM=1 PERMS=1073 AUTHSRC=Anonymous,"
    "2013-10-05T13:05:26.447Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,61,192.168.20.30:41621,192.168.20.30:2525,<,250 XProxyFrom accepted,"
    "2013-10-05T13:05:26.447Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,62,192.168.20.30:41621,192.168.20.30:2525,*,,sending message with RecordId 0 and InternetMessageId <52500E34.7080402@domain.ru>"
    "2013-10-05T13:05:26.447Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,63,192.168.20.30:41621,192.168.20.30:2525,>,MAIL FROM:<user@domain.ru> SIZE=0 AUTH=<>,"
    "2013-10-05T13:05:26.447Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,64,192.168.20.30:41621,192.168.20.30:2525,>,RCPT TO:<user@domain.ru>,"
    "2013-10-05T13:05:26.447Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,65,192.168.20.30:41621,192.168.20.30:2525,<,250 2.1.0 Sender OK,"
    "2013-10-05T13:05:26.447Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,66,192.168.20.30:41621,192.168.20.30:2525,<,250 2.1.5 Recipient OK,"
    "2013-10-05T13:05:26.447Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,67,192.168.20.30:41621,192.168.20.30:2525,>,DATA,"
    "2013-10-05T13:05:26.447Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,68,192.168.20.30:41621,192.168.20.30:2525,<,354 Start mail input; end with <CRLF>.<CRLF>,"
    "2013-10-05T13:05:26.775Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,69,192.168.20.30:41621,192.168.20.30:2525,<,250 2.6.0 <52500E34.7080402@domain.ru> [InternalId=1773821493262] Queued mail for delivery,"
    "2013-10-05T13:06:06.009Z,Внутренний соединитель отправки для вход. подкл. прокси-сервера,08D08FCA2DD6E8F9,70,192.168.20.30:41621,192.168.20.30:2525,*,,Proxying inbound session with session id 08D08FCA2DD6E8FE"

    Hub receive:

    "2013-10-05T13:02:09.950Z,exch\From Intranet,08D08CDC7411A815,61,192.168.20.30:2525,192.168.20.30:41621,>,250 2.6.0 <201310051301.r95D1IIO023747@xx.xx.ru> [InternalId=1773821493258] Queued mail for delivery,"
    "2013-10-05T13:05:26.447Z,exch\From Intranet,08D08CDC7411A815,62,192.168.20.30:2525,192.168.20.30:41621,<,RSET,"
    "2013-10-05T13:05:26.447Z,exch\From Intranet,08D08CDC7411A815,63,192.168.20.30:2525,192.168.20.30:41621,>,250 2.0.0 Resetting,"
    "2013-10-05T13:05:26.447Z,exch\From Intranet,08D08CDC7411A815,64,192.168.20.30:2525,192.168.20.30:41621,<,XPROXYFROM SID=08D08FCA2DD6E8FC IP=192.168.3.106 PORT=1413 DOMAIN=[127.0.0.1] SEQNUM=1 PERMS=1073 AUTHSRC=Anonymous,"
    "2013-10-05T13:05:26.447Z,exch\From Intranet,08D08CDC7411A815,65,192.168.20.30:2525,192.168.20.30:41621,>,250 XProxyFrom accepted,"
    "2013-10-05T13:05:26.447Z,exch\From Intranet,08D08CDC7411A815,66,192.168.20.30:2525,192.168.20.30:41621,<,MAIL FROM:<user@domain.ru> SIZE=0 AUTH=<>,"
    "2013-10-05T13:05:26.447Z,exch\From Intranet,08D08CDC7411A815,67,192.168.20.30:2525,192.168.20.30:41621,*,08D08CDC7411A815;2013-10-05T13:02:09.544Z;2,receiving message"
    "2013-10-05T13:05:26.447Z,exch\From Intranet,08D08CDC7411A815,68,192.168.20.30:2525,192.168.20.30:41621,<,RCPT TO:<user@domain.ru>,"
    "2013-10-05T13:05:26.447Z,exch\From Intranet,08D08CDC7411A815,69,192.168.20.30:2525,192.168.20.30:41621,>,250 2.1.0 Sender OK,"
    "2013-10-05T13:05:26.447Z,exch\From Intranet,08D08CDC7411A815,70,192.168.20.30:2525,192.168.20.30:41621,>,250 2.1.5 Recipient OK,"
    "2013-10-05T13:05:26.447Z,exch\From Intranet,08D08CDC7411A815,71,192.168.20.30:2525,192.168.20.30:41621,<,DATA,"
    "2013-10-05T13:05:26.447Z,exch\From Intranet,08D08CDC7411A815,72,192.168.20.30:2525,192.168.20.30:41621,>,354 Start mail input; end with <CRLF>.<CRLF>,"
    "2013-10-05T13:05:26.447Z,exch\From Intranet,08D08CDC7411A815,73,192.168.20.30:2525,192.168.20.30:41621,*,,receiving message with InternetMessageId <52500E34.7080402@domain.ru>"
    "2013-10-05T13:05:26.775Z,exch\From Intranet,08D08CDC7411A815,74,192.168.20.30:2525,192.168.20.30:41621,>,250 2.6.0 <52500E34.7080402@domain.ru> [InternalId=1773821493262] Queued mail for delivery,"
    "2013-10-05T13:06:06.009Z,exch\From Intranet,08D08CDC7411A815,75,192.168.20.30:2525,192.168.20.30:41621,<,RSET,"
    

    Процесс тормозит FronEnd, почему не пойму. Может есть у кого соображения?

    5 октября 2013 г. 14:40

Ответы

  • Клиенты разные: телнет, вебпочта,..

    Вобщем решил. Во-первых на фронтенде был вручную прикручен connection filtering agent. Работал он странно, IpBlockListProvider отрабатывал, а вот IpAllowListEntry нет. Во-вторых коннектор на фронтенде никак не реагирует на убирание прав ms-Exch-SMTP-Accept-Authoritative-Domain-Sender (продолжает принимать письма от кто-угодно@мой-домен.ру). Поэтому, учитывая что обе роли на одном сервере и сервер один, я решил прибить коннектор на frontend и настроить коннектор на прием из инета прямо на транспорте hub'а, потому что на нем ни одной этой проблемы не наблюдается. (вот убейте, я не могу понять, почему все это нельзя нормально сделать на cas frontend?!)

    После настройки на нем также появилась эта задержка.. Я заподозрил фильтр соединений, который запрашивает провайдеров блэклистов. Посмотрел трафик - действительно, после ввода rcpt to начинаются запросы к провайдерам, но почему то с интервалом 5-10 секунд (запрос-ответ-задержка-запрос-ответ-задержка). Провайдеров 5 штук, в итоге на их опрос уходило 30-50 секунд. 

    Я не понял в чем причина такого поведения. На сервере настроено 2 внутренних днс сервера (стоят на КД). Запросы шли к ним в перемешку, преимущественно к первичному, который и тормозил (кстати для меня странно что вперемешку, я всегда считал что к вторичному днс запросы идут только если первичный не доступен).

    Я убрал первичный сервер, перезапустил сетевое соединение - все залетало. Вернул как было раньше - продолжает летать. 

    PS

    Кстати, вот Get-IpBlockListProvider

    Name                         LookupDomain         Priority
    ---- ------------ --------
    psbl.surriel.com           psbl.surriel.com         8
    bl.spamcop.net            bl.spamcop.net         5
    sbl-xbl.spamhaus.org  sbl-xbl.spamhaus.org 6
    cbl.abuseat.org            cbl.abuseat.org          2
    zen.spamhaus.org        zen.spamhaus.org    3

    Так вот, запросы к ним идут не в порядке Приорита, как написано в документации, а в порядке, в котором они выведены на экран. 


    • Помечено в качестве ответа atg_tech 6 октября 2013 г. 17:58
    • Изменено atg_tech 6 октября 2013 г. 18:06
    6 октября 2013 г. 17:57

Все ответы

  • А что за клиент? Может в нем дело?

    Попробуйте отправить тестовое письмо с помощью Telnet.


    Сазонов Илья http://isazonov.wordpress.com/

    6 октября 2013 г. 15:13
    Модератор
  • Клиенты разные: телнет, вебпочта,..

    Вобщем решил. Во-первых на фронтенде был вручную прикручен connection filtering agent. Работал он странно, IpBlockListProvider отрабатывал, а вот IpAllowListEntry нет. Во-вторых коннектор на фронтенде никак не реагирует на убирание прав ms-Exch-SMTP-Accept-Authoritative-Domain-Sender (продолжает принимать письма от кто-угодно@мой-домен.ру). Поэтому, учитывая что обе роли на одном сервере и сервер один, я решил прибить коннектор на frontend и настроить коннектор на прием из инета прямо на транспорте hub'а, потому что на нем ни одной этой проблемы не наблюдается. (вот убейте, я не могу понять, почему все это нельзя нормально сделать на cas frontend?!)

    После настройки на нем также появилась эта задержка.. Я заподозрил фильтр соединений, который запрашивает провайдеров блэклистов. Посмотрел трафик - действительно, после ввода rcpt to начинаются запросы к провайдерам, но почему то с интервалом 5-10 секунд (запрос-ответ-задержка-запрос-ответ-задержка). Провайдеров 5 штук, в итоге на их опрос уходило 30-50 секунд. 

    Я не понял в чем причина такого поведения. На сервере настроено 2 внутренних днс сервера (стоят на КД). Запросы шли к ним в перемешку, преимущественно к первичному, который и тормозил (кстати для меня странно что вперемешку, я всегда считал что к вторичному днс запросы идут только если первичный не доступен).

    Я убрал первичный сервер, перезапустил сетевое соединение - все залетало. Вернул как было раньше - продолжает летать. 

    PS

    Кстати, вот Get-IpBlockListProvider

    Name                         LookupDomain         Priority
    ---- ------------ --------
    psbl.surriel.com           psbl.surriel.com         8
    bl.spamcop.net            bl.spamcop.net         5
    sbl-xbl.spamhaus.org  sbl-xbl.spamhaus.org 6
    cbl.abuseat.org            cbl.abuseat.org          2
    zen.spamhaus.org        zen.spamhaus.org    3

    Так вот, запросы к ним идут не в порядке Приорита, как написано в документации, а в порядке, в котором они выведены на экран. 


    • Помечено в качестве ответа atg_tech 6 октября 2013 г. 17:58
    • Изменено atg_tech 6 октября 2013 г. 18:06
    6 октября 2013 г. 17:57
  • Я убрал первичный сервер, перезапустил сетевое соединение - все залетало. Вернул как было раньше - продолжает летать. 

    PS

    Кстати, вот Get-IpBlockListProvider

    Name                         LookupDomain         Priority
    ---- ------------ --------
    psbl.surriel.com           psbl.surriel.com         8
    bl.spamcop.net            bl.spamcop.net         5
    sbl-xbl.spamhaus.org  sbl-xbl.spamhaus.org 6
    cbl.abuseat.org            cbl.abuseat.org          2
    zen.spamhaus.org        zen.spamhaus.org    3

    Так вот, запросы к ним идут не в порядке Приорита, как написано в документации, а в порядке, в котором они выведены на экран. 


    1. Ну все-таки надо разобраться в DNS

    2. Подозреваю, что приоритет влияет не на факт запросов (в действительности они могут делаться одновременно), а на порядок внутренней обработки.


    Сазонов Илья http://isazonov.wordpress.com/

    7 октября 2013 г. 2:48
    Модератор
  • 2. Подозреваю, что приоритет влияет не на факт запросов (в действительности они могут делаться одновременно), а на порядок внутренней обработки.


    Ну как бы написано так:

    "Параметр Priority устанавливает порядок, в котором агент фильтра подключений запрашивает настроенные службы поставщика черных списков IP-адресов."

    http://technet.microsoft.com/ru-ru/library/bb124979(v=exchg.150).asp

    • Изменено atg_tech 7 октября 2013 г. 4:50
    7 октября 2013 г. 4:49
  • Ой, ссылка на перевод. :-) Перевод может быть кривым. Да и страница не открывается. Поправьте ссылку.


    Сазонов Илья http://isazonov.wordpress.com/

    7 октября 2013 г. 5:35
    Модератор
  • Ну можно и по английски :)

    "The Priority parameter specifies the order that the Connection Filter agent queries the IP Block list provider services that you have configured"

    http://technet.microsoft.com/en-us/library/bb124979(v=exchg.150).aspx

    7 октября 2013 г. 13:35
  • Это может означать массу вариантов от того, что запросы делаются одновременно, а обрабатываются по приоритету до того, что приоритет вообще игнорируется.

    Вопрос: для вас это создает какую-то проблему?


    Сазонов Илья http://isazonov.wordpress.com/

    7 октября 2013 г. 13:43
    Модератор
  • Для меня нет. Просто указал свое наблюдение, что написаное в документации не совпадает с тем, что мы ожидаем (а мы ожидаем из описания именно порядок запросов и обработки). То что обрабатывается сразу после запроса это факт, я это вижу по трафику: если пришел положительный ответ от первого поставщика, то остальные уже не опрашиваются.

    7 октября 2013 г. 14:59