URL: https://www.opennet.me/cgi-bin/openforum/vsluhboard.cgi
Форум: vsluhforumID1
Нить номер: 85189
[ Назад ]

Исходное сообщение
"timeout after DATA (0) в postfix"

Отправлено gra2f , 07-Май-09 15:24 
Добрый день.
Имеется сервер с установленным postfix+postfixadmin+MySQL+Dovecot. Все вроде бы нормально, но до этого сервера не доходит часть писем. В логах следующее (буквально из последнего):

May  7 15:10:42 PDC postfix/smtpd[5129]: timeout after DATA (0 bytes) from mx45.mail.ru[94.100.176.59]
May  7 15:10:42 PDC postfix/smtpd[5129]: disconnect from mx45.mail.ru[94.100.176.59]
May  7 15:10:43 PDC postfix/smtpd[4849]: timeout after DATA (0 bytes) from mx45.mail.ru[94.100.176.59]
May  7 15:10:43 PDC postfix/smtpd[4849]: disconnect from mx45.mail.ru[94.100.176.59]

Такая проблема имеется с серверами mail.ru, rambler.ru и несколькими корпоративными серверами. Но в то же время такой проблемы не наблюдается с yandex.ru, например.
Излазил весь интернет, нашел описание подобной проблемы из-за нестандартного MTU в сети. Но у нас на всем оборудовании MTU=1500. Провайдер при звонке ему чуть ли не клянется, что у них тоже MTU=1500.
Возникает извечный вопрос - что делать? Помогите, пожалуйста.

Напоследок конфиг postfix-а:

PDC:/home/administrator # postconf -n
alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
body_checks_size_limit = 1024000
broken_sasl_auth_clients = yes
command_directory = /usr/sbin
config_directory = /etc/postfix
daemon_directory = /usr/lib/postfix
data_directory = /var/lib/postfix
debug_peer_level = 2
html_directory = no
inet_interfaces = all
local_recipient_maps = unix:passwd.byname $alias_maps
mail_owner = postfix
mailq_path = /usr/bin/mailq
manpage_directory = /usr/share/man
mydestination = $myhostname, localhost.$mydomain, localhost
mydomain = наш_домен.ru
myhostname = mail.наш_домен.ru
mynetworks = 127.0.0.0/8 192.168.3.0/24
mynetworks_style = host
myorigin = $myhostname
newaliases_path = /usr/bin/newaliases
queue_directory = /var/spool/postfix
readme_directory = no
relay_domains =
sample_directory = /usr/share/doc/packages/postfix/samples
sendmail_path = /usr/sbin/sendmail
setgid_group = maildrop
smtpd_banner = $myhostname ESMTP $mail_name
smtpd_recipient_restrictions = permit_mynetworks         permit_sasl_authenticated        reject_unauth_destination
smtpd_sasl_auth_enable = yes
smtpd_sasl_exceptions_networks = $mynetworks
smtpd_sasl_path = private/auth
smtpd_sasl_security_options = noanonymous
smtpd_sasl_type = dovecot
unknown_local_recipient_reject_code = 550
virtual_alias_maps = proxy:mysql:/usr/local/etc/postfix/mysql_virtual_alias_maps.cf
virtual_gid_maps = static:65534
virtual_mailbox_base = /usr/mail/
virtual_mailbox_domains = proxy:mysql:/usr/local/etc/postfix/mysql_virtual_domains_maps.cf
virtual_mailbox_maps = proxy:mysql:/usr/local/etc/postfix/mysql_virtual_mailbox_maps.cf
virtual_minimum_uid = 65534
virtual_transport = dovecot
virtual_uid_maps = static:65534

здесь 192.168.3.0/24 - наша внутренняя сеть

Если что-то еще нужно дописать, говорите, что.


Содержание

Сообщения в этом обсуждении
"timeout after DATA (0) в postfix"
Отправлено Sarge , 07-Май-09 15:46 
Покажите полный лог с одним таким клиентом - от коннекта до дисконнекта (отследить можно по пиду процесса). И если что-то менялось в master.cf, то и его тоже.

"timeout after DATA (0) в postfix"
Отправлено gra2f , 07-Май-09 15:53 
>Покажите полный лог с одним таким клиентом - от коннекта до дисконнекта
>(отследить можно по пиду процесса). И если что-то менялось в master.cf,
>то и его тоже.

#cat /var/log/mail | grep mx44.mail.ru
May  7 15:41:13 PDC postfix/smtpd[5646]: connect from mx44.mail.ru[94.100.176.58]
May  7 15:41:13 PDC postfix/smtpd[5601]: connect from mx44.mail.ru[94.100.176.58]
May  7 15:41:13 PDC postfix/smtpd[5601]: 667743C995: client=mx44.mail.ru[94.100.176.58]
May  7 15:41:13 PDC postfix/smtpd[5646]: 670CF3C996: client=mx44.mail.ru[94.100.176.58]
May  7 15:41:13 PDC postfix/smtpd[5604]: connect from mx44.mail.ru[94.100.176.58]
May  7 15:41:13 PDC postfix/smtpd[5603]: connect from mx44.mail.ru[94.100.176.58]
May  7 15:41:13 PDC postfix/smtpd[5595]: connect from mx44.mail.ru[94.100.176.58]
May  7 15:41:13 PDC postfix/smtpd[5579]: connect from mx44.mail.ru[94.100.176.58]
May  7 15:41:13 PDC postfix/smtpd[5604]: 75B043C997: client=mx44.mail.ru[94.100.176.58]
May  7 15:41:13 PDC postfix/smtpd[5603]: 770FC3C99E: client=mx44.mail.ru[94.100.176.58]
May  7 15:41:13 PDC postfix/smtpd[5595]: 78E4B3C9A0: client=mx44.mail.ru[94.100.176.58]
May  7 15:41:13 PDC postfix/smtpd[5579]: 79E843C9A1: client=mx44.mail.ru[94.100.176.58]
May  7 15:46:13 PDC postfix/smtpd[5646]: timeout after DATA (0 bytes) from mx44.mail.ru[94.100.176.58]
May  7 15:46:13 PDC postfix/smtpd[5646]: disconnect from mx44.mail.ru[94.100.176.58]
May  7 15:46:13 PDC postfix/smtpd[5601]: timeout after DATA (0 bytes) from mx44.mail.ru[94.100.176.58]
May  7 15:46:13 PDC postfix/smtpd[5601]: disconnect from mx44.mail.ru[94.100.176.58]
May  7 15:46:13 PDC postfix/smtpd[5604]: timeout after DATA (0 bytes) from mx44.mail.ru[94.100.176.58]
May  7 15:46:13 PDC postfix/smtpd[5604]: disconnect from mx44.mail.ru[94.100.176.58]
May  7 15:46:13 PDC postfix/smtpd[5603]: timeout after DATA (0 bytes) from mx44.mail.ru[94.100.176.58]
May  7 15:46:13 PDC postfix/smtpd[5603]: disconnect from mx44.mail.ru[94.100.176.58]
May  7 15:46:13 PDC postfix/smtpd[5595]: timeout after DATA (0 bytes) from mx44.mail.ru[94.100.176.58]
May  7 15:46:13 PDC postfix/smtpd[5595]: disconnect from mx44.mail.ru[94.100.176.58]
May  7 15:46:13 PDC postfix/smtpd[5579]: timeout after DATA (0 bytes) from mx44.mail.ru[94.100.176.58]
May  7 15:46:13 PDC postfix/smtpd[5579]: disconnect from mx44.mail.ru[94.100.176.58]

Вот master.cf:

#
# Postfix master process configuration file.  For details on the format
# of the file, see the Postfix master(5) manual page.
#
# ==========================================================================
# service type  private unpriv  chroot  wakeup  maxproc command + args
#               (yes)   (yes)   (yes)   (never) (100)
# ==========================================================================
smtp      inet  n       -       n       -       -       smtpd
#submission inet n      -       n       -       -       smtpd
#    -o smtpd_etrn_restrictions=reject
#    -o smtpd_client_restrictions=permit_sasl_authenticated,reject
#smtps    inet  n       -       n       -       -       smtpd -o smtpd_tls_wrappermode=yes
#  -o smtpd_tls_wrappermode=yes -o smtpd_sasl_auth_enable=yes
#submission   inet    n       -       n       -       -       smtpd
#  -o smtpd_etrn_restrictions=reject
#  -o smtpd_enforce_tls=yes -o smtpd_sasl_auth_enable=yes
#628      inet  n       -       n       -       -       qmqpd
pickup    fifo  n       -       n       60      1       pickup
cleanup   unix  n       -       n       -       0       cleanup
qmgr      fifo  n       -       n       300     1       qmgr
#qmgr     fifo  n       -       n       300     1       oqmgr
#tlsmgr    unix  -       -       n       1000?   1       tlsmgr
rewrite   unix  -       -       n       -       -       trivial-rewrite
bounce    unix  -       -       n       -       0       bounce
defer     unix  -       -       n       -       0       bounce
trace     unix  -       -       n       -       0       bounce
verify    unix  -       -       n       -       1       verify
flush     unix  n       -       n       1000?   0       flush
proxymap  unix  -       -       n       -       -       proxymap
smtp      unix  -       -       n       -       -       smtp
# When relaying mail as backup MX, disable fallback_relay to avoid MX loops
relay     unix  -       -       n       -       -       smtp
   -o fallback_relay=
#       -o smtp_helo_timeout=5 -o smtp_connect_timeout=5
showq     unix  n       -       n       -       -       showq
error     unix  -       -       n       -       -       error
discard   unix  -       -       n       -       -       discard
local     unix  -       n       n       -       -       local
virtual   unix  -       n       n       -       -       virtual
lmtp      unix  -       -       n       -       -       lmtp
anvil     unix  -       -       n       -       1       anvil
#localhost:10025 inet    n    -    n    -    -    smtpd -o content_filter=
scache      unix    -    -    n    -    1    scache
#
# ====================================================================
# Interfaces to non-Postfix software. Be sure to examine the manual
# pages of the non-Postfix software to find out what options it wants.
#
# Many of the following services use the Postfix pipe(8) delivery
# agent.  See the pipe(8) man page for information about ${recipient}
# and other message envelope options.
# ====================================================================
#
# maildrop. See the Postfix MAILDROP_README file for details.
# Also specify in main.cf: maildrop_destination_recipient_limit=1
#
maildrop  unix  -       n       n       -       -       pipe
flags=DRhu user=vmail argv=/usr/local/bin/maildrop -d ${recipient}
cyrus      unix    -    n    n    -    -    pipe
user=cyrus argv=/usr/lib/cyrus/bin/deliver -e -r ${sender} -m ${extension} ${user}
uucp      unix    -    n    n    -    -    pipe
flags=Fqhu user=uucp argv=uux -r -n -z -a$sender - $nexthop!rmail ($recipient)
ifmail    unix  -       n       n       -       -       pipe
flags=F user=ftn argv=/usr/lib/ifmail/ifmail -r $nexthop ($recipient)
bsmtp     unix  -       n       n       -       -       pipe
flags=Fq. user=foo argv=/usr/local/sbin/bsmtp -f $sender $nexthop $recipient
procmail  unix  -       n       n       -       -       pipe
flags=R user=nobody argv=/usr/bin/procmail -t -m /etc/procmailrc ${sender} ${recipient}
retry     unix  -       -       n       -       -       error
proxywrite unix -       -       n       -       1       proxymap
##
dovecot unix - n n - - pipe flags=DRhu user=nobody:mail argv=/usr/local/lib/dovecot/deliver -d ${recipient}


В нем, соотв-но дописывалась последняя строчка про dovecot.


"timeout after DATA (0) в postfix"
Отправлено gra2f , 07-Май-09 15:57 
или вот по пиду процесса:

#cat /var/log/mail | grep 5646
May  7 15:46:35 PDC postfix/smtpd[5646]: connect from mx44.mail.ru[94.100.176.58]
May  7 15:46:35 PDC postfix/smtpd[5646]: 0A6B83C995: client=mx44.mail.ru[94.100.176.58]
May  7 15:51:35 PDC postfix/smtpd[5646]: timeout after DATA (0 bytes) from mx44.mail.ru[94.100.176.58]
May  7 15:51:35 PDC postfix/smtpd[5646]: disconnect from mx44.mail.ru[94.100.176.58]


"timeout after DATA (0) в postfix"
Отправлено Michael , 07-Май-09 16:43 
покажите еще вывод
netstat -s

"timeout after DATA (0) в postfix"
Отправлено gra2f , 07-Май-09 16:45 
PDC:/home/administrator # netstat -s
Ip:
   237649 total packets received
   0 forwarded
   0 incoming packets discarded
   232807 incoming packets delivered
   299881 requests sent out
   17 dropped because of missing route
   9680 reassemblies required
   4840 packets reassembled ok
   7807 fragments received ok
   15614 fragments created
Icmp:
   201 ICMP messages received
   0 input ICMP message failed.
   ICMP input histogram:
       destination unreachable: 1
       echo requests: 197
       echo replies: 3
   208 ICMP messages sent
   0 ICMP messages failed
   ICMP output histogram:
       destination unreachable: 8
       echo request: 3
       echo replies: 197
IcmpMsg:
       InType0: 3
       InType3: 1
       InType8: 197
       OutType0: 197
       OutType3: 8
       OutType8: 3
Tcp:
   97 active connections openings
   1084 passive connection openings
   22 failed connection attempts
   123 connection resets received
   15 connections established
   176691 segments received
   265758 segments send out
   2261 segments retransmited
   12 bad segments received.
   63 resets sent
Udp:
   29722 packets received
   8 packets to unknown port received.
   2 packet receive errors
   2649 packets sent
   RcvbufErrors: 2
   SndbufErrors: 0
UdpLite:
   InDatagrams: 0
   NoPorts: 0
   InErrors: 0
   OutDatagrams: 0
   RcvbufErrors: 0
   SndbufErrors: 0
TcpExt:
   1 invalid SYN cookies received
   8 resets received for embryonic SYN_RECV sockets
   ArpFilter: 0
   681 TCP sockets finished time wait in fast timer
   2782 delayed acks sent
   4 delayed acks further delayed because of locked socket
   Quick ack mode was activated 95 times
   2145 packets directly queued to recvmsg prequeue.
   23736 packets directly received from backlog
   36884 packets directly received from prequeue
   39132 packets header predicted
   252 packets header predicted and directly queued to user
   TCPPureAcks: 99338
   TCPHPAcks: 13120
   TCPRenoRecovery: 0
   TCPSackRecovery: 668
   TCPSACKReneging: 0
   TCPFACKReorder: 0
   TCPSACKReorder: 5
   TCPRenoReorder: 0
   TCPTSReorder: 2
   TCPFullUndo: 0
   TCPPartialUndo: 3
   TCPDSACKUndo: 0
   TCPLossUndo: 139
   TCPLoss: 685
   TCPLostRetransmit: 44
   TCPRenoFailures: 0
   TCPSackFailures: 87
   TCPLossFailures: 39
   TCPFastRetrans: 907
   TCPForwardRetrans: 16
   TCPSlowStartRetrans: 107
   TCPTimeouts: 441
   TCPRenoRecoveryFail: 0
   TCPSackRecoveryFail: 462
   TCPSchedulerFailed: 0
   TCPRcvCollapsed: 0
   TCPDSACKOldSent: 167
   TCPDSACKOfoSent: 5
   TCPDSACKRecv: 210
   TCPDSACKOfoRecv: 0
   TCPAbortOnSyn: 0
   TCPAbortOnData: 5
   TCPAbortOnClose: 0
   TCPAbortOnMemory: 0
   TCPAbortOnTimeout: 5
   TCPAbortOnLinger: 0
   TCPAbortFailed: 0
   TCPMemoryPressures: 0
   TCPSACKDiscard: 137
   TCPDSACKIgnoredOld: 206
   TCPDSACKIgnoredNoUndo: 3
   TCPSpuriousRTOs: 0
IpExt:
   InNoRoutes: 2
   InTruncatedPkts: 0
   InMcastPkts: 367
   OutMcastPkts: 76
   InBcastPkts: 27500
   OutBcastPkts: 48



"timeout after DATA (0) в postfix"
Отправлено Sarge , 07-Май-09 19:32 
>или вот по пиду процесса:
>
>#cat /var/log/mail | grep 5646
>May  7 15:46:35 PDC postfix/smtpd[5646]: connect from mx44.mail.ru[94.100.176.58]
>May  7 15:46:35 PDC postfix/smtpd[5646]: 0A6B83C995: client=mx44.mail.ru[94.100.176.58]
>May  7 15:51:35 PDC postfix/smtpd[5646]: timeout after DATA (0 bytes) from
>mx44.mail.ru[94.100.176.58]
>May  7 15:51:35 PDC postfix/smtpd[5646]: disconnect from mx44.mail.ru[94.100.176.58]

cat /var/log/mail | grep 0A6B83C995
ifconfig
какая ОС и ядро? ip-опции ядра никакие не крутились?
в фаерволе никаких хитрых правил нет?


"timeout after DATA (0) в postfix"
Отправлено gra2f , 08-Май-09 09:01 
>>или вот по пиду процесса:
>>
>>#cat /var/log/mail | grep 5646
>>May  7 15:46:35 PDC postfix/smtpd[5646]: connect from mx44.mail.ru[94.100.176.58]
>>May  7 15:46:35 PDC postfix/smtpd[5646]: 0A6B83C995: client=mx44.mail.ru[94.100.176.58]
>>May  7 15:51:35 PDC postfix/smtpd[5646]: timeout after DATA (0 bytes) from
>>mx44.mail.ru[94.100.176.58]
>>May  7 15:51:35 PDC postfix/smtpd[5646]: disconnect from mx44.mail.ru[94.100.176.58]
>
>cat /var/log/mail | grep 0A6B83C995

#cat /var/log/mail | grep 0A6B83C995
May  7 15:46:35 PDC postfix/smtpd[5646]: 0A6B83C995: client=mx44.mail.ru[94.100.176.58]


>ifconfig

PDC:/home/administrator # ifconfig
eth0      Link encap:Ethernet  HWaddr 00:80:48:1A:41:80           inet addr:192.168.3.156  Bcast:192.168.3.255  Mask:255.255.255.0
         UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
         RX packets:235762 errors:0 dropped:0 overruns:0 frame:0
         TX packets:274407 errors:0 dropped:0 overruns:0 carrier:0
         collisions:0 txqueuelen:1000
         RX bytes:18603060 (17.7 Mb)  TX bytes:342038984 (326.1 Mb)
         Interrupt:5 Base address:0xaf00

eth1      Link encap:Ethernet  HWaddr 00:80:48:19:EC:2D           inet addr:10.6.107.13  Bcast:10.6.107.15  Mask:255.255.255.252
         UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
         RX packets:73640 errors:0 dropped:0 overruns:0 frame:0
         TX packets:96078 errors:0 dropped:0 overruns:0 carrier:0
         collisions:0 txqueuelen:1000
         RX bytes:19444566 (18.5 Mb)  TX bytes:29480949 (28.1 Mb)
         Interrupt:5 Base address:0xe00

lo        Link encap:Local Loopback           inet addr:127.0.0.1  Mask:255.0.0.0
         UP LOOPBACK RUNNING  MTU:16436  Metric:1
         RX packets:17253 errors:0 dropped:0 overruns:0 frame:0
         TX packets:17253 errors:0 dropped:0 overruns:0 carrier:0
         collisions:0 txqueuelen:0
         RX bytes:2274818 (2.1 Mb)  TX bytes:2274818 (2.1 Mb)

ppp0      Link encap:Point-to-Point Protocol           inet addr:-тут-наш-внешний-ip  P-t-P:10.0.0.2  Mask:255.255.255.255
         UP POINTOPOINT RUNNING NOARP MULTICAST  MTU:1500  Metric:1
         RX packets:46578 errors:0 dropped:0 overruns:0 frame:0
         TX packets:48853 errors:0 dropped:0 overruns:0 carrier:0
         collisions:0 txqueuelen:3
         RX bytes:15179273 (14.4 Mb)  TX bytes:21411366 (20.4 Mb)

>какая ОС и ядро? ip-опции ядра никакие не крутились?

ОС - OpenSUSE 11.0, ядро 2.6.25.5-1.1, не правилось вовсе - стандартное

>в фаерволе никаких хитрых правил нет?

в фаерволе висит только SNAT


"timeout after DATA (0) в postfix"
Отправлено gra2f , 08-Май-09 10:40 
Проблема решена. Провайдер посоветовал все-таки попробовать изменить MTU в туннеле (соединение через VPN). MTU был изменен опытным путем на 1470, после чего все заработало. Пришли даже все старые письма.

"timeout after DATA (0) в postfix"
Отправлено Sarge , 08-Май-09 11:16 
понятно.

"timeout after DATA (0) в postfix"
Отправлено Sarge , 08-Май-09 11:10 
Даже и не знаю. Попробуйте попинговать провайдера и mx44.mail.ru большими пакетами и посмотреть tcpdump-ом какого размера пакеты обратно приходят.

tcpdump icmp
ping mx44.mail.ru -s 1472 -M do