Re: Битые письма

От: Zhukov A. N. <CGatePro_at_mx_ru>
Дата: Fri 19 Nov 2010 - 16:19:49 MSK

Dmitry Akindinov пишет:
> Здравствуйте,
>
> On 2010-11-19 9:07, Zhukov A. N. wrote:
>>
>> Здравствуйте.
>>
>> Поступают жалобы от клиентов на сабж.
>> В ходе "расследования" выяснилось:
>>
>> 10:30:59.720 2 POP-061774([1.2.3.4]) 'user@domain.netu' connected from
>> [1.2.3.4]:1489(temp client)
>> 10:31:00.120 2 POP-061777([1.2.3.4]) 'user@domain.netu' connected from
>> [1.2.3.4]:1490(temp client)
>> 10:32:29.432 2 POP-061774([1.2.3.4]) 0 {3432} retrieved, 2514176 bytes
>> 10:32:34.096 2 POP-061774([1.2.3.4]) deleting 1 message(s)
>> 10:32:34.097 2 MAILBOX(user@domain.netu/INBOX) userbox emptied
>> 10:32:34.097 2 POP-061774([1.2.3.4]) 'user@domain.netu' disconnected
>> ([1.2.3.4]:1489)
>> 10:32:34.176 2 POP-061777([1.2.3.4]) 0 {3432} retrieved, 2398258 bytes
>> 10:32:35.323 2 POP-061777([1.2.3.4]) deleting 1 message(s)
>> 10:32:35.324 2 POP-061777([1.2.3.4]) 'user@domain.netu' disconnected
>> ([1.2.3.4]:1490)
>>
>>
>> Хотелось бы комментов от разработчиков по приведённым логам.
>
> Для сколько-нибудь серьёзного анализа этих логов недостаточно. Можно
> сказать лишь, что действительно происходит что-то нехорошее - в разных
> сессиях зачитывается письмо с одним и тем же UID, но разным размером.
Вот с адресом на отладке (лишние out: с телом письма поскипан):

15:15:26.740 5 POP-578034([1.2.3.4]) out: +OK CommuniGate Pro POP3 
Server 5.1.16 ready <10578034.1290168926@mydomain>\r\n
15:15:26.740 5 POP-578034([1.2.3.4]) inp: user user@domain.netu
15:15:26.740 5 POP-578034([1.2.3.4]) out: +OK please send the PASS\r\n
15:15:26.740 4 POP-578035([1.2.3.4]) got connection on 

[5.6.7.8]:110(mydomain) from [1.2.3.4]:60308

15:15:26.740 5 POP-578035([1.2.3.4]) out: +OK CommuniGate Pro POP3 
Server 5.1.16 ready <10578035.1290168926@mydomain>\r\n
15:15:26.740 5 POP-578035([1.2.3.4]) inp: user user@domain.netu
15:15:26.740 5 POP-578035([1.2.3.4]) out: +OK please send the PASS\r\n
15:15:27.732 5 POP-578034([1.2.3.4]) inp: pass xxxxxxxxxxxx
15:15:27.732 5 POP-578035([1.2.3.4]) inp: pass xxxxxxxxxxxx
15:15:27.733 2 POP-578034([1.2.3.4]) 'user@domain.netu' connected from 

[1.2.3.4]:60307
15:15:27.733 2 POP-578035([1.2.3.4]) 'user@domain.netu' connected from [1.2.3.4]:60308
15:15:27.734 5 POP-578034([1.2.3.4]) out: +OK 1 messages (19347444 bytes)\r\n
15:15:27.734 5 POP-578035([1.2.3.4]) out: +OK 1 messages (19347444 bytes)\r\n
15:15:28.733 5 POP-578034([1.2.3.4]) inp: retr 1 15:15:28.733 5 POP-578034([1.2.3.4]) out: +OK 19347444 bytes will follow\r\n
15:15:28.735 5 POP-578034([1.2.3.4]) out: X-Envelope-To: user@domain.netu\r\nReturn-Path: <user@mydomain>\r\nReceived: from [4.3.2.1] (account user@mydomain HELO [4.3.2.1])\r\n by mydomain (CommuniGate Pro SMTP 5.1.16)\r\n with ESMTPA id 1107108800 for user@domain.netu; ......
15:15:29.732 5 POP-578034([1.2.3.4]) out: S6XJ73b+bzmViv/m/37zf383/zfF\r\nef+g1v4STnGSgXzs6vytPOVMYq7WWPLfNUIn2d1EeS15Mp89va7Ed+eOF1N31fBsoLoxP3d8\r\nFz1dyZwqmfBMcv52tURqHy3vriX85XTSfxdaPigt3x2tNkp3gXTx8iwZ8c/Nzs4VIgeru/Xi\r\nztnV1Vk4mZkvBpZP9w72A0e3vkrw7uB4felie+VAkVOFk0YqWF7a/XSR/TQfVYIzS8XqW

15:15:29.733 5 POP-578035([1.2.3.4]) inp: retr 1 15:15:29.733 5 POP-578035([1.2.3.4]) out: +OK 19347444 bytes will follow\r\n
15:15:29.733 5 POP-578034([1.2.3.4]) out: 91\r\n/wv7xcJB/aRSn9D/a5T9Z5niv4nxP8nU7/ifv+QnPj+/vi7LWYlFzx7uHUYgdRdCThoGgm8a\r\nFLj2i9rSm4ha64vAD4VuIxWkemmvWtyRKsU64dyL+KVvXzWeM1J9P58AdErzuFBZHWJz+xqm\r\nF2oMNBQUE2kpnsyklzPJNAiKS9L9G8aCZzJWQojglwR5bpZDPpqJkGV98sxuD/GwFIZNxsTx\r\nNGtOYm1tLRJPRxIpBge

15:15:29.733 5 POP-578034([1.2.3.4]) out: I/D1zthDf9a6XgerSYSJ1+ioYPZw5X60vzp59SV9u1UK5AVu16\r\n9ubkPH9wvnJ2UVSS18v/n70r63ncNtf3/hfarH3fN2vfrM2SLMnaNU0mQIHeJRf9+ceDc9ee\r\nNGkzSeagHwHaAgyRJvku5PuQD3NB3ZFGPIhJIaZ6jYuzEAnDkdOWOqZK9TAU25rmXMHULi5l\r\nQ1EN9cDi13q+EIQaaNAUtjWoVI5MRfkB7LDtXRMSn5SOKPP

15:15:29.733 5 POP-578035([1.2.3.4]) out: X-Envelope-To: user@domain.netu\r\nReturn-Path: <user@mydomain>\r\nReceived: from [4.3.2.1] (account user@mydomain HELO [4.3.2.1])\r\n by mydomain (CommuniGate Pro SMTP 5.1.16)\r\n with ESMTPA id 1107108800 for user@domain.netu; .......
15:15:31.147 5 POP-578035([1.2.3.4]) out: q31vkm2omQGobbs9VImmq2fL7fCKX1u3bTNhmNYGhuRFHDbWxgCdhQCCkciPVmGHPv\r\nb970NOauXSAgzVxYvBacPs6vYThGUJTnpRkII0a55Asi5tna7KOGJ3pDwZvb6E1ldWzVkRB9\r\nlqadiE1n7vY5rB3p6WnSxx14oHg6S8H0Wf3XrPrKqBRLJM5A3VxQT82Tuq0Ae+0NErFLjaVw\r\n1gyaR3eSWXsinBsCRYMp4U2j97TBFTC

15:15:31.147 2 POP-578034([1.2.3.4]) 0 {362} retrieved, 19347447 bytes
15:15:31.147 5 POP-578034([1.2.3.4]) inp: dele 1
15:15:31.147 4 POP-578034([1.2.3.4]) 0 {362} marked deleted
15:15:31.147 5 POP-578034([1.2.3.4]) out: +OK marked deleted\r\n
15:15:31.148 5 POP-578035([1.2.3.4]) out: 

LUSflWG63WE79aVb5P9Z6l/61dRv5+p32AKyPr/n\r\nNuAlvhfBAd5b6S8haIkFJoZn8aOQCSUIJ4B75kw8wVgvl8Vn/rk7j9TzINLAeX8mhfhCjcOp\r\nMMSHOXIdGppF9sCdyRy8kgjVj32zH8zgMz/blsGc4zDamYkIZZ83IqgoHB9SryCL8GkoA/mA\r\nL+qvzyF6Rt4JsfquwWs5jS8OE9GY+PPvPW44bZev5vJLOCUXlmTLQLL0L

15:15:31.736 5 POP-578035([1.2.3.4]) out: Uzw72BnXpJ47C4ikkTTwb+QFesD1BEdhQOGtRKEhRQaS9rYr0pYOgG9YeB0ZX7vR0UKGG2B6\r\nkrJ9JADw1Eywbpx0VYeUASCU8qH2TccpuemBRaLgFdCECJ1Miy2JU4sqgWzBcUmA7Gu1hr4B\r\nCcu4tjONQ8FjcPElqAkHKXdUiqm70bBk8fT2JswYOl1So9m3kVqq9gMkzkXJ0iHWxanyBVBY\r\n4Ke1mcnPm6PLBcywSeImK4VFi

15:15:31.739 5 POP-578034([1.2.3.4]) inp: quit
15:15:31.740 4 POP-578034([1.2.3.4]) disconnecting
15:15:31.740 5 POP-578034([1.2.3.4]) out: +OK CommuniGate Pro POP3 

Server connection closed\r\n
15:15:31.740 2 POP-578034([1.2.3.4]) deleting 1 message(s) 15:15:31.740 5 POP-578035([1.2.3.4]) out: Px+J0ql707L/7FiMbkDoovK0srK4urpfJSyUC9psF+NJ6u\r\nLsO8y3dp+GIJNsRaAXB4SbdPeIVj7uDgdw5rx/v1g6Mq+kcV36yUO6+P9veK+9UD/G+pWCo/\r\nX+rAnwK8RpyeACs49dUbQLryCu7ToC/UWkwcXEKfS1F3V0O/iCUL5eJ4pVRZLJVhR124/RH+\r\ng/Gbi3/1aQvJa5zmr3hT6n6abEmNJ3grstW9WJHfp54GhhCa1m7

15:15:31.740 2 POP-578034([1.2.3.4]) 'user@domain.netu' disconnected ([1.2.3.4]:60307)
15:15:31.740 4 POP-578034([1.2.3.4]) closing connection 15:15:31.740 5 POP-578035([1.2.3.4]) out: 66FeaWBLJ5mdk83mw72T\r\nJx9Onjft74haANvHhPPLL8wnanXpxcP6SWYTqsZM5PHySamJP3gismV4LnmEQXSgL/RAeZRQ\r\nNZM9WS89fHPyhCC/dQK9abDwwJ7A4uJQdO8EC1hJaDp/ArDawx2JXQQbNqbIwgw4w9+J0s4v\r\nkp/bBPYO3+c3sZz4ndcdijy7pYnN2e+wQrLulRJi3bOTjWCxCOLLuIhPjuD9wyNEoWAFuJx9\r\ny

15:15:31.740 4 POP-578034([1.2.3.4]) releasing stream 15:15:31.740 2 POP-578035([1.2.3.4]) 0 {362} retrieved, 14590538 bytes << --------- Вот здесь ведь известно, что передано не заявленное число байт? >>

15:15:31.740 5 POP-578035([1.2.3.4]) inp: dele 1
15:15:31.740 4 POP-578035([1.2.3.4]) 0 {362} marked deleted
15:15:31.740 5 POP-578035([1.2.3.4]) out: +OK marked deleted\r\n
15:15:32.742 5 POP-578035([1.2.3.4]) inp: quit
15:15:32.742 4 POP-578035([1.2.3.4]) disconnecting
15:15:32.742 5 POP-578035([1.2.3.4]) out: +OK CommuniGate Pro POP3 

Server connection closed\r\n
15:15:32.742 2 POP-578035([1.2.3.4]) deleting 1 message(s) 15:15:32.742 2 POP-578035([1.2.3.4]) 'user@domain.netu' disconnected ([1.2.3.4]:60308)
15:15:32.752 4 POP-578035([1.2.3.4]) closing connection 15:15:32.752 4 POP-578035([1.2.3.4]) releasing stream

>
>> Домен и IP левые, остальное правда.
>> CGP - 5.1.16
>
> Уже в 5.2 было зафиксировано несколько проблем при работе с почовыми
> ящиками. Ветка 5.1 уже вряд ли будет обновляться, поэтому решение одно
> - использовать более свежие версии CGPro.
>
Оно бы , да, но вот дополнительная лицензия на 30.000 п/я сколько станет, не подскажете?
Из функциала CGP используется у нас только почта.
>> Спасибо.
>>
>
Получено Fri Nov 19 13:21:14 2010