[ILUG] extremely slow pop3, but imap is fine

[Andrew - Afrihost]

On Friday 27 March 2009 11:00:14 Kae Verens wrote:
> Kenn Humborg wrote:
>  >> On Thu, Mar 26, 2009 at 5:04 PM, Kae Verens <kae at verens.com> wrote:
>  >>> all was running perfectly for months until today.
>  >>
>  >> Any patches applied? Anything showing on the logs? Tried to restart
>  >> services/box ?
>  >
>  > Run strace -p <PID> on the server process.  It might provide
>  > clues as to what's going on during the delays.
>  >
>  > Later,
>  > Kenn
>
> here's some output from strace. looks like something to do with "EAGAIN"

man 2 write says:
       EAGAIN The file descriptor fd has been marked non-blocking (O_NONBLOCK) 
       and the write would block.

the poll and gettimeofday calls are probably select().

In this content, getting EAGAIN means that the CPU can send data faster than 
the network can accept it -- which is normal (normally).  It looks like you 
are sending about 12kbytes per second.

If you haven't made progress, dump the traffic from the server and the 
client's point of view, while you reproduce the error behaviour.  If you can 
synchronise the clocks, that will make things better:
	ntpdate pool.ntp.org
	tcpdump -s0 -w dump.pcap port 110

&:-)

> poll([{fd=4, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=2,
> events=POLLERR|POLLHUP|POLLNVAL}, {fd=0,
> events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=1,
> events=POLLOUT|POLLERR|POLLHUP|POLLNVAL, revents=POLLOUT}], 4, 7362) = 1
> gettimeofday({1238144209, 439345}, {0, 0}) = 0
> write(1, "U2/zfhCsb8/599SnAbpb95S4iTXDXBlG"..., 820) = 820
> setsockopt(1, SOL_TCP, TCP_CORK, [1], 4) = 0
> pread64(9, "lAsm\nQpbOoKCrRiwsgJMAeOVYoAztcWq"..., 4096, 4370432) = 4096
> write(1, "\r\n0/Z8DwF4RytmCb/n+LvCGCXwlXhK8E"..., 4134) = 4134
> pread64(9, "YPYABETE8FgQrlAYRxiUgCQEC5OgAp1h"..., 4096, 4374528) = 4096
> write(1, "\r\nxQ4sSsxfE4nAwQIlX4hct0lIfvVxKO"..., 4134) = 4134
> pread64(9, "QQiAGIYiAGJYjshD6ztQhEAIZACGM6GQ"..., 4096, 4378624) = 4096
> write(1, "\r\nZLViXL7L6R9oJ+yaEEXDoaRCkv6hrJ"..., 4134) = 3584
> write(1, "LuXb\r\nHEyxFtgRYi9K1SkXg85LoywmJ5"..., 550) = -1 EAGAIN
> (Resource temporarily unavailable) setsockopt(1, SOL_TCP, TCP_CORK, [0], 4)
> = 0
> gettimeofday({1238144209, 439986}, NULL) = 0
> poll([{fd=4, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=2,
> events=POLLERR|POLLHUP|POLLNVAL}, {fd=0,
> events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=1,
> events=POLLOUT|POLLERR|POLLHUP|POLLNVAL, revents=POLLOUT}], 4, 7102) = 1
> gettimeofday({1238144210, 92244}, {0, 0}) = 0
> write(1, "LuXb\r\nHEyxFtgRYi9K1SkXg85LoywmJ5"..., 550) = 550
> setsockopt(1, SOL_TCP, TCP_CORK, [1], 4) = 0
> pread64(9, "xh1ZPKCh4bFQucAD0lo433yFczLJ3Kvj"..., 4096, 4382720) = 4096
> write(1, "\r\nBrg+igL7ZWPffzlvWNrwI3M7OAY7le"..., 4134) = 4134
> pread64(9, "DYiKvFC3AUfIZTURQpWAk\nwBxMcFkgTQ"..., 4096, 4386816) = 4096
> write(1, "\r\nZOwAAKTvKgOmAcwECr6eMYMrQV7/OI"..., 4134) = 4134
> pread64(9, "/KziLP\nvsMhOCHC7HksnAi+ZmFlyRYgQ"..., 4096, 4390912) = 4096
> write(1, "\r\ngJ3D3YVgk7p6xyc8q5I7e0rSzWoEKq"..., 4134) = 4134
> pread64(9, "m0MZAV+hA4qYwpw5xVmYwIDIWuJIAZlc"..., 4096, 4395008) = 4096
> write(1, "\r\nIpL0ctaWQUsfIkROF1tVZZLEsLgtRH"..., 4134) = 1128
> write(1, "ZV2Q5JDMt0ehNfVlcgMdjSsLAaHg7fRR"..., 3006) = -1 EAGAIN (Resource
> temporarily unavailable) setsockopt(1, SOL_TCP, TCP_CORK, [0], 4) = 0
> gettimeofday({1238144210, 92937}, NULL) = 0
>
> for the other guys, the problem appears in Linux and Windows. no virus
> checker between Dovecot and the client.
>
> kae



-- 
System Administrator
Afrihost.com - the best web hosting ever

Tel   :  +27 11 234 5045
Fax   :  +27 86 552 2000
Email :  ａｎｄｒｅｗｍ@ａｆｒｉｈｏｓｔ.ｃｏｍ
Web   :  http://www.afrihost.com/
----------------------------------------------------------------
If e-mail doesn't work, try knee-mail