Active Dynamic Cluster. Непонятная задержка.

От: Alexandr Yatsuk <CGatePro_at_mx_ru>
Дата: Fri 26 Jan 2007 - 19:31:14 MSK

Добрый день.
Настроили (видно еще недонастроили) active dynamic cluster из четырех машин. (2 fronted - 2 beckend). Проводим тесты с аккаунтом в котором 7500 писем. Возникает непонятная задержка примерно в 10 секунд.

Ниже приведены логи сесий, из которых видно, что бэкенд в период с 18:28:21.212 4 MAILBOX(test1@example.com/Znatoky) parsed 7383 message files, lastUID=7383 по
18:28:27.400 5 XIMSS-002053([192.168.68.61]) out: <folderReport id="A010" folder="Znatoky" mode="init" messages="1"/>\000<response id="A010"/>\000

Кто сталкивался?
Какие параметры можно повертеть, которые повлияют на быстродействие кластера?

(Притом все сервера не загружены и тормозов по дисковой системе нет)

Лог сесии с фронтенда.

18:28:19.088 4 XIMSS-141378([193.239.68.7]) got connection on [192.168.68.61]:11024(example.com) from [193.239.68.7]:54845
18:28:19.088 5 XIMSS-141378([193.239.68.7]) inp(39): <login id="L0387" method="CRAM-MD5" />\000
18:28:19.088 5 XIMSS-141378([193.239.68.7]) SASL-0(CRAM-MD5) out: <141378.1169742499@mf1.test.example.com>
18:28:19.088 5 XIMSS-141378([193.239.68.7]) out: <challenge value="PDE0MTM3OC4xMTY5NzQyNDk5QG1mMS50ZXN0LmJpZ21pci5uZXQ+"/>\000
18:28:19.090 5 XIMSS-141378([193.239.68.7]) inp(97): <auth id="L0387" value="dGVzdDFAYmlnbWlyLm5ldCA2MzRjMWM0NDZmMzFmZDc3MzExNjRmYzY4MTM2MWYxZA==" />\000
18:28:19.090 5 XIMSS-141378([193.239.68.7]) SASL-0(CRAM-MD5) inp: test1@example.com 634c1c446f31fd7731164fc681361f1d
18:28:19.092 4 XIMSS-141378 connecting to [192.168.68.71]:11024
18:28:19.092 4 XIMSS-141378([193.239.68.7]) authenticating: [193.239.68.7]:54845 CRAM-MD5 test1@example.com <141378.1169742499@mf1.test.example.com> ^5
18:28:19.092 5 XIMSS-141378 out: <login id="L0387" method="PROXY" authData="WzE5My4yMzkuNjguN106NTQ4NDUgQ1JBTS1NRDUgdGVzdDFAYmlnbWlyLm5ldCA8MTQxMzc4LjExNjk3NDI0OTlAbWYxLnRlc3QuYmlnbWlyLm5ldD4gNjM0YzFjNDQ2ZjMxZmQ3NzMxMTY0ZmM2ODEzNjFmMWQ="/>\000
18:28:19.093 5 XIMSS-141378 inp: <session urlID="1992-5a5PKT1NFJvFJ5tN7hLK-kmbdnjb" userName="test1@example.com"/>
18:28:19.093 5 XIMSS-141378 inp: <response id="L0387"/>
18:28:19.093 2 XIMSS-141378([193.239.68.7]) 'test1@example.com' linked from [193.239.68.7]:54845 to [192.168.68.71]:11024
18:28:19.093 5 XIMSS-141378([193.239.68.7]) out: <session urlID="1992-5a5PKT1NFJvFJ5tN7hLK-kmbdnjb" userName="test1@example.com" />\000<response id="L0387"/>\000
18:28:19.093 4 XIMSS-141378 proxy started
18:28:19.095 5 XIMSS-141378([193.239.68.7]) inp(218): <folderOpen id="A010" folder="Znatoky" mailbox="Znatoky" sortField="INTERNALDATE" sortOrder="desc" filterField="Subject" filter="Subscribe.ru"><field>FLAGS</field><field>From</field><field>Subject</field></folderOpen>\000
18:28:19.095 5 XIMSS-141378 out: <folderOpen id="A010" folder="Znatoky" mailbox="Znatoky" sortField="INTERNALDATE" sortOrder="desc" filterField="Subject" filter="Subscribe.ru"><field>FLAGS</field><field>From</field><field>Subject</field></folderOpen>\000
18:28:27.401 5 XIMSS-141378([193.239.68.7]) out: <folderReport id="A010" folder="Znatoky" mode="init" messages="1"/>\000<response id="A010"/>\000
18:28:27.402 5 XIMSS-141378([193.239.68.7]) inp(43): <folderClose id="A011" folder="Znatoky" />\000
18:28:27.402 5 XIMSS-141378 out: <folderClose id="A011" folder="Znatoky" />\000
18:28:27.403 5 XIMSS-141378([193.239.68.7]) out: <response id="A011"/>\000
18:28:27.404 5 XIMSS-141378([193.239.68.7]) inp(19): <bye id="J7511" />\000
18:28:27.404 5 XIMSS-141378 out: <bye id="J7511" />\000
18:28:27.404 5 XIMSS-141378([193.239.68.7]) out: <response id="J7511"/>\000
18:28:27.404 4 XIMSS-141378([193.239.68.7]) server has closed the connection
18:28:27.404 4 XIMSS-141378 closing connection
18:28:27.404 2 XIMSS-141378([193.239.68.7]) proxy connection closed
18:28:27.404 4 XIMSS-141378([193.239.68.7]) closing connection
18:28:27.405 4 XIMSS-141378([193.239.68.7]) releasing stream

Лог сесии с бэкенда.

8:28:19.092 4 XIMSS-002053([192.168.68.61]) got connection on [192.168.68.71]:11024(example.com) from [192.168.68.61]:51558

18:28:19.092 5 XIMSS-002053([192.168.68.61]) inp(207): <login id="L0387" method="PROXY" authData="WzE5My4yMzkuNjguN106NTQ4NDUgQ1JBTS1NRDUgdGVzdDFAYmlnbWlyLm5ldCA8MTQxMzc4LjExNjk3NDI0OTlAbWYxLnRlc3QuYmlnbWlyLm5ldD4gNjM0YzFjNDQ2ZjMxZmQ3NzMxMTY0ZmM2ODEzNjFmMWQ="/>\000
18:28:19.092 5 XIMSS-002053([192.168.68.61]) PROXY SASL(CRAM-MD5): name='test1@example.com', auth='634c1c446f31fd7731164fc681361f1d', key='<141378.1169742499@mf1.test.example.com>'
18:28:19.092 4 ACCOUNT(test1@example.com) login(XIMSS) from [193.239.68.7]
18:28:19.092 2 XIMSS-002053([192.168.68.61]) 'test1@example.com' connected from [193.239.68.7]:54845 via [192.168.68.61]:51558
18:28:19.092 2 WEBUSER-001992(test1@example.com) XIMSS logged in from [193.239.68.7]
18:28:19.092 5 XIMSS-002053([192.168.68.61]) out: <session urlID="1992-5a5PKT1NFJvFJ5tN7hLK-kmbdnjb" userName="test1@example.com"/>\000<response id="L0387"/>\000
18:28:19.095 5 XIMSS-002053([192.168.68.61]) inp(218): <folderOpen id="A010" folder="Znatoky" mailbox="Znatoky" sortField="INTERNALDATE" sortOrder="desc" filterField="Subject" filter="Subscribe.ru"><field>FLAGS</field><field>From</field><field>Subject</field></folderOpen>\000
18:28:19.097 4 MAILBOX(test1@example.com/Znatoky) directory mailbox opened
18:28:19.097 4 MAILBOX(test1@example.com/Znatoky) opened
18:28:19.097 5 MAILBOX(test1@example.com/Znatoky) parsing
18:28:21.212 4 MAILBOX(test1@example.com/Znatoky) parsed 7383 message files, lastUID=7383
18:28:27.400 5 XIMSS-002053([192.168.68.61]) out: <folderReport id="A010" folder="Znatoky" mode="init" messages="1"/>\000<response id="A010"/>\000
18:28:27.402 5 XIMSS-002053([192.168.68.61]) inp(43): <folderClose id="A011" folder="Znatoky" />\000
18:28:27.402 4 MAILBOX(test1@example.com/Znatoky) directory mailbox closed
18:28:27.402 5 XIMSS-002053([192.168.68.61]) out: <response id="A011"/>\000
18:28:27.404 5 XIMSS-002053([192.168.68.61]) inp(19): <bye id="J7511" />\000
18:28:27.404 5 XIMSS-002053([192.168.68.61]) out: <response id="J7511"/>\000
18:28:27.404 2 WEBUSER-001992(test1@example.com) session with [193.239.68.7] closed
18:28:27.404 2 XIMSS-002053([192.168.68.61]) 'test1@example.com' disconnected ([193.239.68.7]:54845)
18:28:27.404 4 XIMSS-002053([192.168.68.61]) closing connection

________________

Alexandr L.Yatsuk
FIVT-UANIC Получено Fri Jan 26 16:31:22 2007