Re: failed to receive message body (xxx bytes). Error Code=read time-out

От: Nikolay A. Kostyakov <CGatePro_at_mx_ru>
Дата: Thu 05 Jul 2007 - 16:32:13 MSD

virt пишет:
> Здравствуйте, 

> Неужели никто не сталкивался?
> Проблема уже начинает сильно беспокоить.
> Из логов видно что сообщение начинает передаваться, потом передача данных прекращается  и через 5 минут соединение отваливается по time-out. 
> При этом в момент прекращения передачи, удаленный хост нормально пингуется, я могу зайти телнетом на 25 порт и так далее.
> На сервере, где крутится CGP работает также apache и jabber сервер и проблем с сетевыми соединениями с ними нет.
> Отловить закономерность какие сообщения принимаются нормально, а какие нет, я не смог(везде разные клиенты, разный размер письма).
> Что еще можно проверить в данной ситуации?
>
> С уважением, Александр.
>
> v> Здравствуйте,
> v> Часть писем перестала приниматься. В логах следующее:
> v> Перерыв инет по этой проблеме, я пробывал менять патчкорд, свич, сетевую - безрезультатно.
>
>
>

У нас бывают такие проблемы и обычно это связано с ошибками на канальном уровне .
На всей цепочке от клиента до сервера включительно. Если перечислить навскидку это проявлялось в результате : неисправности сетевой платы клиента , автодетект "дурил" по скорости между сетевой платой и свичом , неисправности оптического конвертера по пути следования , какие-то не стыковки были при пробрасывании vlanов или vpn через свичи ( сетевикам кажется приходилось жестко прописывать MTU на свичах иначе пакеты портились и их контрольные суммы не совпадали )... 
> v> 10:38:29.07 4 SMTPI-13666([81.22.63.4]) got connection on [xxx.xxx.xxx.xxx:25]
> v> 10:38:29.07 4 SMTPI-13666([81.22.63.4]) rsp: 220 domain.ru ESMTP 4.3.12
> v> 10:38:29.09 4 SMTPI-13666([81.22.63.4]) cmd: EHLO mail.metromail.ru
> v> 10:38:29.09 4 SMTPI-13666([81.22.63.4]) rsp: 250-domain.ru we
> v> trust you mail.metromail.ru\r\n250-DSN\r\n250-SIZE
> v> 31457280\r\n250-STARTTLS\r\n250-AUTH=LOGIN\r\n250-AUTH LOGIN PLAIN
> v> CRAM-MD5
> v> DIGEST-MD5\r\n250-ETRN\r\n250-TURN\r\n250-ATRN\r\n250-NO-SOLICITING\r\n250-8BITMIME\r\n250-HELP\r\n250-PIPEL
> v> 10:38:29.12 4 SMTPI-13666([81.22.63.4]) cmd: STARTTLS
> v> 10:38:29.12 4 SMTPI-13666([81.22.63.4]) rsp: 220 please start a TLS connection
> v> 10:38:29.14 4 SMTPI-13666([81.22.63.4]) SSLv2 client hello as
> v> TLSv1: method=DES3_SHA, session=10579 < 00 00 29 53 46 89 EE E5 25
> v> DB A0 CC 1D 18 BA B1 65 48 F9 1B AD 9A 0E 2C C5 05 C5 98 87 8C 10 28>
> v> 10:38:29.14 4 SMTPI-13666([81.22.63.4]) TLS handshake: sending 'server_hello'
> v> 10:38:29.14 4 SMTPI-13666([81.22.63.4]) TLS handshake: sending the certificate
> v> 10:38:29.14 4 SMTPI-13666([81.22.63.4]) TLS handshake: sending 'hello_done'
> v> 10:38:29.47 4 SMTPI-13666([81.22.63.4]) TLS client key exchange processed
> v> 10:38:29.47 4 SMTPI-13666([81.22.63.4]) security initiated
> v> 10:38:29.47 4 SMTPI-13666([81.22.63.4]) TLS 'change cipher' processed
> v> 10:38:29.47 4 SMTPI-13666([81.22.63.4]) TLS 'change cipher' sending
> v> 10:38:29.47 4 SMTPI-13666([81.22.63.4]) TLS 'finish handshake' processed
> v> 10:38:29.47 4 SMTPI-13666([81.22.63.4]) TLS handshake: sending 'finished'
> v> 10:38:29.47 4 SMTPI-13666([81.22.63.4]) secure connection
> v> (DES3_SHA) accepted, session 10579
> v> 10:38:29.52 4 SMTPI-13666([81.22.63.4]) cmd: EHLO mail.metromail.ru
> v> 10:38:29.52 4 SMTPI-13666([81.22.63.4]) rsp: 250-domain.ru we
> v> trust you mail.metromail.ru\r\n250-DSN\r\n250-SIZE
> v> 31457280\r\n250-AUTH=LOGIN\r\n250-AUTH LOGIN PLAIN CRAM-MD5
> v> DIGEST-MD5\r\n250-ETRN\r\n250-TURN\r\n250-ATRN\r\n250-NO-SOLICITING\r\n250-8BITMIME\r\n250-HELP\r\n250-PIPELINING\r\n250 EHL
> v> 10:38:29.81 4 SMTPI-13666([81.22.63.4]) cmd: MAIL
> v> FROM:<samara@vashdom.ru> SIZE=456535 BODY=8BITMIME
> v> 10:38:29.81 4 SMTPI-13666([81.22.63.4]) rsp: 250 samara@vashdom.ru sender accepted
> v> 10:38:29.81 4 SMTPI-13666([81.22.63.4]) cmd: RCPT
> v> TO:<oleg.b@sama.domain.ru> ORCPT=rfc822;oleg.b@sama.domain.ru
> v> 10:38:29.81 4 SMTPI-13666([81.22.63.4]) rsp: 250
> v> oleg.b@sama.domain.ru will leave the Internet
> v> 10:38:29.81 4 SMTPI-13666([81.22.63.4]) cmd: DATA
> v> 10:38:29.81 4 SMTPI-13666([81.22.63.4]) rsp: 354 Enter mail, end with "." on a line by itself
> v> 10:43:29.82 3 SMTPI-13666([81.22.63.4]) failed to receive message
> v> body (391 bytes). Error Code=read time-out
> v> 10:43:29.82 4 SMTPI-13666([81.22.63.4]) TLS connection is closing
> v> 10:43:29.82 4 SMTPI-13666([81.22.63.4]) closing connection
> v> 10:43:29.82 4 SMTPI-13666([81.22.63.4]) releasing stream
>
>
>
>
>
> v> логи tcpdump:
> v> 10:38:29.057827 IP (tos 0x0, ttl  55, id 58894, offset 0, flags
> v> [DF], proto: TCP (6), length: 64) smtp.metromail.ru.58075 > domain.ru.smtp: S, cksum 0x4542
> v>  (correct), 1164102708:1164102708(0) win 65535 <mss
> v> 1360,nop,wscale 2,nop,nop,timestamp 3905674247 0,sackOK,eol>
> v> 10:38:29.078441 IP (tos 0x0, ttl  55, id 58898, offset 0, flags
> v> [DF], proto: TCP (6), length: 52) smtp.metromail.ru.58075 > domain.ru.smtp: ., cksum 0x49c2
> v>  (correct), ack 144389333 win 33026 <nop,nop,timestamp 3905674268 131888244>
> v> 10:38:29.098680 IP (tos 0x0, ttl  55, id 58903, offset 0, flags
> v> [DF], proto: TCP (6), length: 52) smtp.metromail.ru.58075 > domain.ru.smtp: ., cksum 0x4982
> v>  (correct), ack 32 win 33018 <nop,nop,timestamp 3905674289 131888264>
> v> 10:38:29.098930 IP (tos 0x0, ttl  55, id 58904, offset 0, flags
> v> [DF], proto: TCP (6), length: 76) smtp.metromail.ru.58075 > domain.ru.smtp: P, cksum 0x2b61
> v>  (correct), 0:24(24) ack 32 win 33026 <nop,nop,timestamp 3905674289 131888264>
> v> 10:38:29.121917 IP (tos 0x0, ttl  55, id 58907, offset 0, flags
> v> [DF], proto: TCP (6), length: 52) smtp.metromail.ru.58075 > domain.ru.smtp: ., cksum 0x487c
> v>  (correct), ack 280 win 32964 <nop,nop,timestamp 3905674312 131888285>
> v> 10:38:29.122042 IP (tos 0x0, ttl  55, id 58908, offset 0, flags
> v> [DF], proto: TCP (6), length: 62) smtp.metromail.ru.58075 > domain.ru.smtp: P, cksum 0x05d4
> v>  (correct), 24:34(10) ack 280 win 33026 <nop,nop,timestamp 3905674312 131888285>
> v> 10:38:29.141408 IP (tos 0x0, ttl  55, id 58910, offset 0, flags
> v> [DF], proto: TCP (6), length: 52) smtp.metromail.ru.58075 > domain.ru.smtp: ., cksum 0x47ef
> v>  (correct), ack 315 win 33017 <nop,nop,timestamp 3905674332 131888308>
> v> 10:38:29.143155 IP (tos 0x0, ttl  55, id 58911, offset 0, flags
> v> [DF], proto: TCP (6), length: 181) smtp.metromail.ru.58075 > domain.ru.smtp: P 34:163(129)
> v> ack 315 win 33026 <nop,nop,timestamp 3905674333 131888308>
> v> 10:38:29.163519 IP (tos 0x0, ttl  55, id 58912, offset 0, flags
> v> [DF], proto: TCP (6), length: 52) smtp.metromail.ru.58075 > domain.ru.smtp: ., cksum 0x4700
> v>  (correct), ack 394 win 33006 <nop,nop,timestamp 3905674353 131888329>
> v> 10:38:29.164644 IP (tos 0x0, ttl  55, id 58913, offset 0, flags
> v> [DF], proto: TCP (6), length: 52) smtp.metromail.ru.58075 > domain.ru.smtp: ., cksum 0x42f8
> v>  (correct), ack 1742 win 32689 <nop,nop,timestamp 3905674354 131888329>
> v> 10:38:29.185258 IP (tos 0x0, ttl  55, id 58917, offset 0, flags
> v> [DF], proto: TCP (6), length: 52) smtp.metromail.ru.58075 > domain.ru.smtp: ., cksum 0x40d5
> v>  (correct), ack 1966 win 32970 <nop,nop,timestamp 3905674375 131888350>
> v> 10:38:29.466227 IP (tos 0x0, ttl  55, id 58962, offset 0, flags
> v> [DF], proto: TCP (6), length: 242) smtp.metromail.ru.58075 > domain.ru.smtp: P 163:353(190)
> v>  ack 1966 win 33026 <nop,nop,timestamp 3905674656 131888350>
> v> 10:38:29.497836 IP (tos 0x0, ttl  55, id 58969, offset 0, flags
> v> [DF], proto: TCP (6), length: 52) smtp.metromail.ru.58075 > domain.ru.smtp: ., cksum 0x3d6a
> v>  (correct), ack 1972 win 33024 <nop,nop,timestamp 3905674687 131888663>
> v> 10:38:29.518824 IP (tos 0x0, ttl  55, id 58971, offset 0, flags
> v> [DF], proto: TCP (6), length: 52) smtp.metromail.ru.58075 > domain.ru.smtp: ., cksum 0x3d1c
> v>  (correct), ack 2017 win 33014 <nop,nop,timestamp 3905674709 131888684>
> v> 10:38:29.527818 IP (tos 0x0, ttl  55, id 58972, offset 0, flags
> v> [DF], proto: TCP (6), length: 105) smtp.metromail.ru.58075 > domain.ru.smtp: P 353:406(53)
> v> ack 2017 win 33026 <nop,nop,timestamp 3905674718 131888684>
> v> 10:38:29.548932 IP (tos 0x0, ttl  55, id 58976, offset 0, flags
> v> [DF], proto: TCP (6), length: 52) smtp.metromail.ru.58075 > domain.ru.smtp: ., cksum 0x3bdc
> v>  (correct), ack 2278 win 32960 <nop,nop,timestamp 3905674739 131888714>
> v> 10:38:29.817909 IP (tos 0x0, ttl  55, id 59021, offset 0, flags
> v> [DF], proto: TCP (6), length: 217) smtp.metromail.ru.58075 > domain.ru.smtp: P 406:571(165)
> v>  ack 2278 win 33026 <nop,nop,timestamp 3905675008 131888714>
> v> 10:38:29.838273 IP (tos 0x0, ttl  55, id 59026, offset 0, flags
> v> [DF], proto: TCP (6), length: 52) smtp.metromail.ru.58075 > domain.ru.smtp: ., cksum 0x387f
> v>  (correct), ack 2347 win 33008 <nop,nop,timestamp 3905675028 131889004>
> v> 10:38:29.858636 IP (tos 0x0, ttl  55, id 59031, offset 0, flags
> v> [DF], proto: TCP (6), length: 52) smtp.metromail.ru.58075 > domain.ru.smtp: ., cksum 0x37cc
> v>  (correct), ack 2509 win 32985 <nop,nop,timestamp 3905675048 131889024>
> v> 10:43:29.843578 IP (tos 0x0, ttl  55, id 55155, offset 0, flags
> v> [DF], proto: TCP (6), length: 40) smtp.metromail.ru.58075 > domain.ru.smtp: R, cksum 0x8056
> v>  (correct), 1164103280:1164103280(0) win 0
>
>
>
> ##################################################################
> Вы получили это сообщение потому, что подписаны на список рассылки
>   <CGatePro@mx.ru>.
>
> Чтобы отписаться, отправьте сообщение на адрес <CGatePro-off@mx.ru>
> Чтобы переключиться в режим дайджеста - mailto:<CGatePro-digest@mx.ru>
> Чтобы переключиться в индексный режим - mailto:<CGatePro-index@mx.ru>
> Для административных запросов адрес <CGatePro-request@mx.ru>
> Архив списка: http://mx.demos.su/lists/cgp-russian/
>
>
>
>   



-- 
С уважением Николай Костяков.
IPтел. 101-101
ICQ 15294462
Отдел безопасности информационных систем и интернет-технологий ДИС.
Получено Thu Jul 05 12:32:07 2007

Этот архив был сгенерирован hypermail 2.1.8 : Thu 05 Jul 2007 - 17:14:51 MSD