Почему Mdaemon не может отправить исходящую корреспонденцию?

Question

[Nabi Alimetov]

Здравствуйте!
Почтовый сервер - Mdaemon 15.0.1. Операционная система - Windows Server 2003 R2 Enterprise Edition.
Некоторые сообщения не отправляются и остаются в Удаленной очереди. В логе SMTP out такие сообщения:
1.
Tue 2018-12-11 11:07:45.831: Session 517348; child 0001
Tue 2018-12-11 11:07:45.831: Parsing message
Tue 2018-12-11 11:07:45.831: * From: [e-mail]
Tue 2018-12-11 11:07:45.831: * To: [e-mail]
Tue 2018-12-11 11:07:45.831: * Subject:
Tue 2018-12-11 11:07:45.831: * Size (bytes): 847427
Tue 2018-12-11 11:07:45.831: * Message-ID: <004d01d49128$52e31480$f8a93d80$@dgstk.ru>
Tue 2018-12-11 11:07:45.847: Resolving MX record for mrser.ru (DNS Server: 192.168.5.129)...
Tue 2018-12-11 11:07:46.003: * P=020 S=000 D=mrser.ru TTL=(10) MX=[mail.mrser.ru]
Tue 2018-12-11 11:07:46.003: * P=030 S=001 D=mrser.ru TTL=(10) MX=[mail1.mrser.ru]
Tue 2018-12-11 11:07:46.003: Attempting SMTP connection to mail.mrser.ru
Tue 2018-12-11 11:07:46.003: Resolving A record for mail.mrser.ru (DNS Server: 192.168.5.129)...
Tue 2018-12-11 11:07:46.003: * D=mail.mrser.ru TTL=(10) A=[92.42.8.82]
Tue 2018-12-11 11:07:46.003: Attempting SMTP connection to 92.42.8.82:25
Tue 2018-12-11 11:07:46.003: * 92.42.8.82 in connection failure cache for up to 5 minutes due to previous connection failure(s)
Tue 2018-12-11 11:07:46.003: Attempting SMTP connection to mail1.mrser.ru
Tue 2018-12-11 11:07:46.003: Resolving A record for mail1.mrser.ru (DNS Server: 192.168.5.129)...
Tue 2018-12-11 11:07:46.003: * D=mail1.mrser.ru TTL=(8) A=[91.143.157.2]
Tue 2018-12-11 11:07:46.003: Attempting SMTP connection to 91.143.157.2:25
Tue 2018-12-11 11:07:46.003: Waiting for socket connection...
Tue 2018-12-11 11:07:46.034: * Connection established 192.168.5.133:2913 --> 91.143.157.2:25
Tue 2018-12-11 11:07:46.034: Waiting for protocol to start...
Tue 2018-12-11 11:07:46.050: <-- 220 mail.mrser.ru ESMTP MDaemon 15.0.3; Tue, 11 Dec 2018 11:07:45 +0300
Tue 2018-12-11 11:07:46.066: --> EHLO mail2.dgstk.ru
Tue 2018-12-11 11:07:46.081: <-- 250-mail.mrser.ru Hello mail2.dgstk.ru, pleased to meet you
Tue 2018-12-11 11:07:46.081: <-- 250-ETRN
Tue 2018-12-11 11:07:46.081: <-- 250-AUTH LOGIN CRAM-MD5 PLAIN
Tue 2018-12-11 11:07:46.081: <-- 250-8BITMIME
Tue 2018-12-11 11:07:46.081: <-- 250-ENHANCEDSTATUSCODES
Tue 2018-12-11 11:07:46.081: <-- 250 SIZE 16000000
Tue 2018-12-11 11:07:46.081: --> MAIL From: SIZE=847427
Tue 2018-12-11 11:07:46.112: <-- 250 2.1.0 Sender OK
Tue 2018-12-11 11:07:46.112: --> RCPT To:
Tue 2018-12-11 11:07:46.144: <-- 250 2.1.5 Recipient OK
Tue 2018-12-11 11:07:46.144: --> DATA
Tue 2018-12-11 11:07:46.159: <-- 354 Enter mail, end with .
Tue 2018-12-11 11:07:46.159: Sending to [91.143.157.2]
Tue 2018-12-11 11:08:05.175: * Socket error 10054 - Соединение было перезапущено на друго конце!
Tue 2018-12-11 11:08:05.175: Ошибка при записи в сокет
Tue 2018-12-11 11:08:05.175: Socket connection closed by the other side (how rude!)
Tue 2018-12-11 11:08:05.175: * Socket error 10053 - Соединение отменено.
Tue 2018-12-11 11:08:05.175: Соединение прервано
Tue 2018-12-11 11:08:05.175: * Возраст этого сообщения равен 2 минутам; осталось 58 минут его нахождения в этой очереди

2.
Tue 2018-12-11 11:07:55.941: Session 517355; child 0003
Tue 2018-12-11 11:07:55.941: Parsing message
Tue 2018-12-11 11:07:55.941: * From: [e-mail]
Tue 2018-12-11 11:07:55.941: * To: [e-mail]
Tue 2018-12-11 11:07:55.941: * Subject:
Tue 2018-12-11 11:07:55.941: * Size (bytes): 1609218
Tue 2018-12-11 11:07:55.941: * Message-ID:
Tue 2018-12-11 11:07:55.956: Resolving MX record for mail.ru (DNS Server: 192.168.5.129)...
Tue 2018-12-11 11:07:55.956: * P=010 S=000 D=mail.ru TTL=(9) MX=[mxs.mail.ru]
Tue 2018-12-11 11:07:55.956: Attempting SMTP connection to mxs.mail.ru
Tue 2018-12-11 11:07:55.956: Resolving A record for mxs.mail.ru (DNS Server: 192.168.5.129)...
Tue 2018-12-11 11:07:55.956: * D=mxs.mail.ru TTL=(0) A=[94.100.180.104]
Tue 2018-12-11 11:07:55.956: * D=mxs.mail.ru TTL=(0) A=[94.100.180.31]
Tue 2018-12-11 11:07:55.956: Randomly picked 94.100.180.31 from list of possible hosts
Tue 2018-12-11 11:07:55.956: Attempting SMTP connection to 94.100.180.31:25
Tue 2018-12-11 11:07:55.956: Waiting for socket connection...
Tue 2018-12-11 11:08:16.941: * Socket error 10060 - Тайм-аут соединения.
Tue 2018-12-11 11:08:16.941: * 94.100.180.31 added to connection failure cache for 5 minutes
Tue 2018-12-11 11:08:16.941: * Возраст этого сообщения равен 0 минутам; осталось 60 минут его нахождения в этой очереди
Tue 2018-12-11 11:08:16.941: SMTP session terminated (Bytes in/out: 0/0)

При этом телнетом 94.100.180.31:25 открывается.

Comments

[Maksim]

nslookup -type=mx dgstk.ru 8.8.8.8
╤хЁтхЁ: google-public-dns-a.google.com
Address: 8.8.8.8

DNS request timed out.
timeout was 2 seconds.
*** google-public-dns-a.google.com не удалось найти dgstk.ru: Non-existent domain

[Nabi Alimetov]

Maksim, ответ есть от dns сервера. Я это в первую очередь проверил. Я просто тут изменил доменное имя.

[Maksim]

Nabi Alimetov, секреты....
в ни каких сектах (спам базах не состоите, проверяли)?

[Nabi Alimetov]

Maksim, проверял через этот ресурс https://mxtoolbox.com/. В спам базах нет нас.
Секретов нет. Просто думал, что это не важно для решения задачи.

[Maksim]

Tue 2018-12-11 11:07:46.159: Sending to [91.143.157.2]
Tue 2018-12-11 11:08:05.175: * Socket error 10054 - Соединение было перезапущено на друго конце!

Tue 2018-12-11 11:07:55.956: Waiting for socket connection...
Tue 2018-12-11 11:08:16.941: * Socket error 10060 - Тайм-аут соединения.

в обоих случаях порядка 20 сек, может поиграться (увеличить какие нибудь таймеры?)

[Nabi Alimetov]

Maksim, таймеры итак на 30 с и 60 с

[Владимир Дубровин]

Антивирус на машине стоит? По netstat -no | find ":25 " каком процессу принадлежит pid с которого идет установка исходящих соединений?

[Владимир Дубровин]

По картине очень похоже, что отваливался сетевой интерфейс, новое соединение не прошло, а потом и ранее установленное старое отвалилось.

[Nabi Alimetov]

Владимир Дубровин, есть, конечно: касперский и сигнатурные базы обновляются каждый день. Сейчас запустил dr.web cureit: нашел какой-то троян Trojan.Eps.38782 и вирус Adware.Toolbar.493 (deltaTB.exe). Если найдет еще вирусы, я тут напишу дополнительно. Команду netstat -no | find ":25" тоже выполнил: pid принадлежит Mdaemon. А исходящие соединения процесс разве с 25 порта инициирует?! Я думал почтовый сервер соединяется на 25 порт с какого-либо другого, выбранного рандомным методом.

[Nabi Alimetov]

Владимир Дубровин, соединение устанавливается и передача данных тоже идет, но потом отваливается. А новое соединение не устанавливается. Пишет, что уже есть в кеше. В общем проблема решилась, но не знаю благодаря чему. А из-за медленного исходящего канала Интернета это может быть?

[Владимир Дубровин]

исходящие соединения идут на порт 25, эта регулярка покажет и их.
Если исходящие соединения идут через антивирус, то вполне вероятно, что проблемы с ним, например какое-то из писем его надолго подвешивает.
Из-за медленного канала может быть, но для этого канал должен быть очень медленным, т.е. пинг должен ходить несколько секунда или теряться должно несколько десятков процентов пакетов.

Answer 1

[Nabi Alimetov]

Иногда необходимо просто дождаться, пока письма уйдут в Интернет.