Re: [Dovecot] POP3 Slow
Hi, Thanks to everybody for your contributions to my issue. The hardware usage is minimal. I was actually thinking that I have missed something major in the strace output, that I had posted and that would be pointed out. Beyond that I have looked into every possible angle, and I did run a further network analysis of TCP connections ( ftp ), as suggested, and found out that there were retransmissions and duplicate acks. The problems are extraneous to dovecot, which in my opinion is the best IMAP/POP3 server out there. This issue can be considered closed. . --- On Mon, 11/10/10, Charles Marcus wrote: From: Charles Marcus Subject: Re: [Dovecot] POP3 Slow To: dovecot@dovecot.org Date: Monday, 11 October, 2010, 11:06 PM On 2010-10-11 12:15 PM, Jerry wrote: > As you are probably aware, most posters supply either too little or > too much info. When in doubt, I would favor the "too much" scenario > though. It saves asking for further info and greatly facilitates > diagnosing the problem. I agree, but you miss my point... Providing 'uname -a' output is *redundant* (except for old/outdated versions that do not include this info) when doveconf -n output is provided... -- Best regards, Charles
Re: [Dovecot] POP3 Slow
On 2010-10-11 12:15 PM, Jerry wrote: > As you are probably aware, most posters supply either too little or > too much info. When in doubt, I would favor the "too much" scenario > though. It saves asking for further info and greatly facilitates > diagnosing the problem. I agree, but you miss my point... Providing 'uname -a' output is *redundant* (except for old/outdated versions that do not include this info) when doveconf -n output is provided... -- Best regards, Charles
Re: [Dovecot] POP3 Slow
On Mon, 11 Oct 2010 11:56:38 -0400 Charles Marcus articulated: > Actually, doveconf -n output should include similar output as uname -a > (as well as dovecot version) at the top... It was meant as a semi all inclusive listings. I could have included tcpdump, etc.; however, I just wanted to convey the general idea to the OP. Obviously, 'dovecot -n' would not be required for say a Postfix specific problem. As you are probably aware, most posters supply either too little or too much info. When in doubt, I would favor the "too much" scenario though. It saves asking for further info and greatly facilitates diagnosing the problem. -- Jerry ✌ dovecot.u...@seibercom.net Disclaimer: off-list followups get on-list replies or get ignored. Please do not ignore the Reply-To header. __ She was good at playing abstract confusion in the same way a midget is good at being short. Clive James, on Marilyn Monroe
Re: [Dovecot] POP3 Slow
On 2010-10-11 11:15 AM, Jerry wrote: > To the OP, the output of "uname -a", "dovecot -n" Actually, doveconf -n output should include similar output as uname -a (as well as dovecot version) at the top... -- Best regards, Charles
Re: [Dovecot] POP3 Slow
On Mon, 11 Oct 2010 09:32:35 -0500 Ken A articulated: > Well, to keep us from wasting our time, and to get relevant answers > efficiently, it's good practice to outline your hardware, and what > you have already tried in your first post. What does your hardware > utilization look like? In the future, could we also please trim the superfluous material from these posts. To the OP, the output of "uname -a", "dovecot -n" as well as the configuration files of other pertinent applications in addition to what modifications you have made and all pertinent log entries would prove extremely useful. Listing your hardware, as previously mentioned, is also invaluable in some situations. Some of these you have obviously all ready supplied and, or been requested to supply. -- Jerry ✌ dovecot.u...@seibercom.net Disclaimer: off-list followups get on-list replies or get ignored. Please do not ignore the Reply-To header. __ One big pile is better than two little piles. Arlo Guthrie
Re: [Dovecot] POP3 Slow
On 10/8/2010 11:04 PM, Avinash Mishra wrote: Hi I have tried out the Performance Tuning measures, I do not think that an upgrade is going to help as most of the features can be incorporated with the current version itself. ( already done that btw ) Well, to keep us from wasting our time, and to get relevant answers efficiently, it's good practice to outline your hardware, and what you have already tried in your first post. What does your hardware utilization look like? Ken I am unable to find any anomalies in the trace, or am I missing something ? The only part that seems to be not ok, is the EAGAIN -1 return from the write() function. I did run a protocol analyzer trace on the TCP transaction, when the POP3 clients were connecting and discovered a lot of Re-Transmissions and Duplicate ACK packets. --- On Fri, 8/10/10, Ken A wrote: From: Ken A Subject: Re: [Dovecot] POP3 Slow To: dovecot@dovecot.org Date: Friday, 8 October, 2010, 7:24 PM Have you tried the suggestions on improving performance in the wiki? http://wiki.dovecot.org/PerformanceTuning You will need to upgrade to take advantage of several of them.. Ken On 10/7/2010 11:40 PM, Avinash Mishra wrote: Hi, I am running both IMAP/POP3 services. Recently, the POP3 users started complaining of slow performance. I tried to resolve it by advising them to trim their inbox, but to no avail. Kindly advise as I am not able to resolve this issue. dovecot -n: # 1.0.7: /etc/dovecot.conf ssl_cert_file: /etc/dovecot.cert.pem ssl_key_file: /etc/dovecot.key.pem login_dir: /var/run/dovecot/login login_executable(default): /usr/libexec/dovecot/imap-login login_executable(imap): /usr/libexec/dovecot/imap-login login_executable(pop3): /usr/libexec/dovecot/pop3-login mail_location: maildir:~/Maildir mail_executable(default): /usr/libexec/dovecot/imap mail_executable(imap): /usr/libexec/dovecot/imap mail_executable(pop3): /usr/libexec/dovecot/pop3 mail_plugin_dir(default): /usr/lib/dovecot/imap mail_plugin_dir(imap): /usr/lib/dovecot/imap mail_plugin_dir(pop3): /usr/lib/dovecot/pop3 pop3_client_workarounds(default): pop3_client_workarounds(imap): pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh auth default: mechanisms: plain login passdb: driver: pam userdb: driver: passwd = sstrace -tt -o log -p: 18:45:55.425819 gettimeofday({1286457355, 425856}, {4294966966, 0}) = 0 18:45:55.425901 write(1, "hQIKACgAoAKACgAoAKACgAoASgBaBhQI"..., 1683) = 1683 18:45:55.425987 setsockopt(1, SOL_TCP, TCP_CORK, [1], 4) = 0 18:45:55.426044 pread64(9, "UAFABQAUAFABQBR+zxT31x5qBsBcUAOu"..., 4096, 20480) = 4096 18:45:55.426137 write(1, "\r\nAUAFABQAUAFABQAUAFABQAUAFABQAU"..., 4134) = 4134 18:45:55.426204 pread64(9, "/AJ5p+VAg+zwd4k/7\n5FAB9nh/55J/3y"..., 4096, 24576) = 4096 18:45:55.426298 write(1, "\r\nAC+UmP4v++jR8gsHkp7/APfRosuwWI"..., 4134) = 4134 18:45:55.426373 pread64(9, "FA\nBQAUAFABQAUAFABQAUAFABQAUAFAB"..., 4096, 28672) = 4096 18:45:55.426466 write(1, "\r\nKBBQAUAFABQAUAFABQAUAFABQAUAFA"..., 4134) = 1729 18:45:55.426528 write(1, "rSs+4B+8/2f1oswD956r+VGow/eeq/lR"..., 2405) = -1 EAGAIN (Resource temporarily unavailable) 18:45:55.426600 setsockopt(1, SOL_TCP, TCP_CORK, [0], 4) = 0 18:45:55.426674 gettimeofday({1286457355, 426704}, NULL) = 0 18:45:55.426752 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}], 4, 4839) = 1 ([{fd=1, revents=POLLOUT}]) 18:45:55.803792 gettimeofday({1286457355, 803819}, {4294966966, 0}) = 0 18:45:55.803867 write(1, "rSs+4B+8/2f1oswD956r+VGow/eeq/lR"..., 2405) = 2405 18:45:55.803943 setsockopt(1, SOL_TCP, TCP_CORK, [1], 4) = 0 18:45:55.803998 pread64(9, "BQAUAFABQAUAFABQAUAFABQAUAFABQAU"..., 4096, 32768) = 4096 18:45:55.804091 write(1, "\r\nAFABQAUAFABQAUAFABQAUAFABQAUAF"..., 4134) = 4134 18:45:55.804158 pread64(9, "QH+Dbzj0zQBbVCrjDfIFxtx+tAD6ACgA"..., 4096, 36864) = 4096 18:45:55.804251 write(1, "\r\njQBQgtryBSqPDknJJBJJ96ALe6QXCp"..., 4134) = 2221 18:45:55.804327 write(1, "86U5IzwPagCxcQtI0BXHyOGP0waAJ6AF"..., 1913) = -1 EAGAIN (Resource temporarily unavailable) 18:45:55.804399 setsockopt(1, SOL_TCP, TCP_CORK, [0], 4) = 0 18:45:55.804449 gettimeofday({1286457355, 804466}, NULL) = 0 18:45:55.804497 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}], 4, 4461) = 1 ([{fd=1, revents=POLLOUT}]) 18:45:56.189834 gettimeofday({1286457356, 189861}, {4294966966, 0}) = 0 18:45:56.1
Re: [Dovecot] POP3 Slow
I did run a protocol analyzer trace on the TCP transaction, when the POP3 clients were connecting and discovered a lot of Re-Transmissions and Duplicate ACK packets. Then the first thing I would do is check the network connection. Maybe you have a wrecked network card, switch port ot et cetera. Try running another protocol, like FTP, over the same connection. If you get similar errors you can rule out dovecot. JC
Re: [Dovecot] POP3 Slow
On Sat, 2010-10-09 at 09:34 +0530, Avinash Mishra wrote: > Hi > > I have tried out the Performance Tuning measures, I do not think that an > > upgrade is going to help as most of the features can be incorporated > > with the current version itself. ( already done that btw ) > The problem is, you are asking for support for a version that is no longer supported, just because it is "current" in debians eyes, does not mean it is so, 1.0 is deprecated, some time ago now. But, apart from other obvious things, have your checked your disks for problems. Your config looks fine anyway, if you have not changed anything, no other OS packaged updated recently, have restarted dovecot etc, checked messages kernel and daemon logs as well, maybe, late at night issue a 'shutdown -F now ' to force checks. Upgrading to at least v1.2 (.15 is current) will give you some performance boost with pop3 over 1.0x
Re: [Dovecot] POP3 Slow
Hi I have tried out the Performance Tuning measures, I do not think that an upgrade is going to help as most of the features can be incorporated with the current version itself. ( already done that btw ) I am unable to find any anomalies in the trace, or am I missing something ? The only part that seems to be not ok, is the EAGAIN -1 return from the write() function. I did run a protocol analyzer trace on the TCP transaction, when the POP3 clients were connecting and discovered a lot of Re-Transmissions and Duplicate ACK packets. --- On Fri, 8/10/10, Ken A wrote: From: Ken A Subject: Re: [Dovecot] POP3 Slow To: dovecot@dovecot.org Date: Friday, 8 October, 2010, 7:24 PM Have you tried the suggestions on improving performance in the wiki? http://wiki.dovecot.org/PerformanceTuning You will need to upgrade to take advantage of several of them.. Ken On 10/7/2010 11:40 PM, Avinash Mishra wrote: > Hi, > > > > I am running both IMAP/POP3 services. Recently, the POP3 users started > complaining of slow performance. > > > > I tried to resolve it by advising them to trim their inbox, but to no avail. > > > > Kindly advise as I am not able to resolve this issue. > > > > dovecot -n: > > > > # 1.0.7: /etc/dovecot.conf > > ssl_cert_file: /etc/dovecot.cert.pem > > ssl_key_file: /etc/dovecot.key.pem > > login_dir: /var/run/dovecot/login > > login_executable(default): /usr/libexec/dovecot/imap-login > > login_executable(imap): /usr/libexec/dovecot/imap-login > > login_executable(pop3): /usr/libexec/dovecot/pop3-login > > mail_location: maildir:~/Maildir > > mail_executable(default): /usr/libexec/dovecot/imap > > mail_executable(imap): /usr/libexec/dovecot/imap > > mail_executable(pop3): /usr/libexec/dovecot/pop3 > > mail_plugin_dir(default): /usr/lib/dovecot/imap > > mail_plugin_dir(imap): /usr/lib/dovecot/imap > > mail_plugin_dir(pop3): /usr/lib/dovecot/pop3 > > pop3_client_workarounds(default): > > pop3_client_workarounds(imap): > > pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh > > auth default: > > mechanisms: plain login > > passdb: > > driver: pam > > userdb: > > driver: passwd > > > > = > > > > sstrace -tt -o log -p: > > > > 18:45:55.425819 gettimeofday({1286457355, 425856}, {4294966966, 0}) = 0 > > 18:45:55.425901 write(1, "hQIKACgAoAKACgAoAKACgAoASgBaBhQI"..., 1683) = 1683 > > 18:45:55.425987 setsockopt(1, SOL_TCP, TCP_CORK, [1], 4) = 0 > > 18:45:55.426044 pread64(9, "UAFABQAUAFABQBR+zxT31x5qBsBcUAOu"..., 4096, > 20480) = 4096 > > 18:45:55.426137 write(1, "\r\nAUAFABQAUAFABQAUAFABQAUAFABQAU"..., 4134) = 4134 > > 18:45:55.426204 pread64(9, "/AJ5p+VAg+zwd4k/7\n5FAB9nh/55J/3y"..., 4096, > 24576) = 4096 > > 18:45:55.426298 write(1, "\r\nAC+UmP4v++jR8gsHkp7/APfRosuwWI"..., 4134) = 4134 > > 18:45:55.426373 pread64(9, "FA\nBQAUAFABQAUAFABQAUAFABQAUAFAB"..., 4096, > 28672) = 4096 > > 18:45:55.426466 write(1, "\r\nKBBQAUAFABQAUAFABQAUAFABQAUAFA"..., 4134) = 1729 > > 18:45:55.426528 write(1, "rSs+4B+8/2f1oswD956r+VGow/eeq/lR"..., 2405) = -1 > EAGAIN (Resource temporarily unavailable) > > 18:45:55.426600 setsockopt(1, SOL_TCP, TCP_CORK, [0], 4) = 0 > > 18:45:55.426674 gettimeofday({1286457355, 426704}, NULL) = 0 > > 18:45:55.426752 > 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}], 4, 4839) = 1 ([{fd=1, > revents=POLLOUT}]) > > 18:45:55.803792 gettimeofday({1286457355, 803819}, {4294966966, 0}) = 0 > > 18:45:55.803867 write(1, "rSs+4B+8/2f1oswD956r+VGow/eeq/lR"..., 2405) = 2405 > > 18:45:55.803943 setsockopt(1, SOL_TCP, TCP_CORK, [1], 4) = 0 > > 18:45:55.803998 pread64(9, "BQAUAFABQAUAFABQAUAFABQAUAFABQAU"..., 4096, > 32768) = 4096 > > 18:45:55.804091 write(1, "\r\nAFABQAUAFABQAUAFABQAUAFABQAUAF"..., 4134) = 4134 > > 18:45:55.804158 pread64(9, "QH+Dbzj0zQBbVCrjDfIFxtx+tAD6ACgA"..., 4096, > 36864) = 4096 > > 18:45:55.804251 write(1, "\r\njQBQgtryBSqPDknJJBJJ96ALe6QXCp"..., 4134) = 2221 > > 18:45:55.804327 write(1, "86U5IzwPagCxcQtI0BXHyOGP0waAJ6AF"..., 1913) = -1 > EAGAIN (Resource temporarily unavailable) > > 18:45:55.804399 setsockopt(1, SOL_TCP, TCP_CORK, [0], 4) = 0 > > 18:45:55.804449 gettimeofday({1286457355, 804466}, NULL) = 0 > > 18:45:55.804497 > poll([{fd=4, events=P
Re: [Dovecot] POP3 Slow
Have you tried the suggestions on improving performance in the wiki? http://wiki.dovecot.org/PerformanceTuning You will need to upgrade to take advantage of several of them.. Ken On 10/7/2010 11:40 PM, Avinash Mishra wrote: Hi, I am running both IMAP/POP3 services. Recently, the POP3 users started complaining of slow performance. I tried to resolve it by advising them to trim their inbox, but to no avail. Kindly advise as I am not able to resolve this issue. dovecot -n: # 1.0.7: /etc/dovecot.conf ssl_cert_file: /etc/dovecot.cert.pem ssl_key_file: /etc/dovecot.key.pem login_dir: /var/run/dovecot/login login_executable(default): /usr/libexec/dovecot/imap-login login_executable(imap): /usr/libexec/dovecot/imap-login login_executable(pop3): /usr/libexec/dovecot/pop3-login mail_location: maildir:~/Maildir mail_executable(default): /usr/libexec/dovecot/imap mail_executable(imap): /usr/libexec/dovecot/imap mail_executable(pop3): /usr/libexec/dovecot/pop3 mail_plugin_dir(default): /usr/lib/dovecot/imap mail_plugin_dir(imap): /usr/lib/dovecot/imap mail_plugin_dir(pop3): /usr/lib/dovecot/pop3 pop3_client_workarounds(default): pop3_client_workarounds(imap): pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh auth default: mechanisms: plain login passdb: driver: pam userdb: driver: passwd = sstrace -tt -o log -p: 18:45:55.425819 gettimeofday({1286457355, 425856}, {4294966966, 0}) = 0 18:45:55.425901 write(1, "hQIKACgAoAKACgAoAKACgAoASgBaBhQI"..., 1683) = 1683 18:45:55.425987 setsockopt(1, SOL_TCP, TCP_CORK, [1], 4) = 0 18:45:55.426044 pread64(9, "UAFABQAUAFABQBR+zxT31x5qBsBcUAOu"..., 4096, 20480) = 4096 18:45:55.426137 write(1, "\r\nAUAFABQAUAFABQAUAFABQAUAFABQAU"..., 4134) = 4134 18:45:55.426204 pread64(9, "/AJ5p+VAg+zwd4k/7\n5FAB9nh/55J/3y"..., 4096, 24576) = 4096 18:45:55.426298 write(1, "\r\nAC+UmP4v++jR8gsHkp7/APfRosuwWI"..., 4134) = 4134 18:45:55.426373 pread64(9, "FA\nBQAUAFABQAUAFABQAUAFABQAUAFAB"..., 4096, 28672) = 4096 18:45:55.426466 write(1, "\r\nKBBQAUAFABQAUAFABQAUAFABQAUAFA"..., 4134) = 1729 18:45:55.426528 write(1, "rSs+4B+8/2f1oswD956r+VGow/eeq/lR"..., 2405) = -1 EAGAIN (Resource temporarily unavailable) 18:45:55.426600 setsockopt(1, SOL_TCP, TCP_CORK, [0], 4) = 0 18:45:55.426674 gettimeofday({1286457355, 426704}, NULL) = 0 18:45:55.426752 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}], 4, 4839) = 1 ([{fd=1, revents=POLLOUT}]) 18:45:55.803792 gettimeofday({1286457355, 803819}, {4294966966, 0}) = 0 18:45:55.803867 write(1, "rSs+4B+8/2f1oswD956r+VGow/eeq/lR"..., 2405) = 2405 18:45:55.803943 setsockopt(1, SOL_TCP, TCP_CORK, [1], 4) = 0 18:45:55.803998 pread64(9, "BQAUAFABQAUAFABQAUAFABQAUAFABQAU"..., 4096, 32768) = 4096 18:45:55.804091 write(1, "\r\nAFABQAUAFABQAUAFABQAUAFABQAUAF"..., 4134) = 4134 18:45:55.804158 pread64(9, "QH+Dbzj0zQBbVCrjDfIFxtx+tAD6ACgA"..., 4096, 36864) = 4096 18:45:55.804251 write(1, "\r\njQBQgtryBSqPDknJJBJJ96ALe6QXCp"..., 4134) = 2221 18:45:55.804327 write(1, "86U5IzwPagCxcQtI0BXHyOGP0waAJ6AF"..., 1913) = -1 EAGAIN (Resource temporarily unavailable) 18:45:55.804399 setsockopt(1, SOL_TCP, TCP_CORK, [0], 4) = 0 18:45:55.804449 gettimeofday({1286457355, 804466}, NULL) = 0 18:45:55.804497 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}], 4, 4461) = 1 ([{fd=1, revents=POLLOUT}]) 18:45:56.189834 gettimeofday({1286457356, 189861}, {4294966966, 0}) = 0 18:45:56.189908 write(1, "86U5IzwPagCxcQtI0BXHyOGP0waAJ6AF"..., 1913) = 1913 18:45:56.189982 setsockopt(1, SOL_TCP, TCP_CORK, [1], 4) = 0 18:45:56.190039 pread64(9, "uJ5Y9W/wC+jTC4CNf9r/vo0XC4uwep/w"..., 4096, 40960) = 4096 18:45:56.190136 write(1, "\r\nMN/e/Siwai4b+9+lKwBtb++fyosAbW"..., 4134) = 4134 18:45:56.190204 pread64(9, "0pAGBQAUALQAUAJQAtA\nBQAlAC0AFABQ"..., 4096, 45056) = 4096 18:45:56.190295 write(1, "\r\nB5Ef939aLLsGvcPs8WMbBRoGvcPs8X"..., 4134) = 1253 18:45:56.190370 write(1, "gAoAKACgAoAKACgAoAKACgAoAKACgAoA"..., 2881) = -1 EAGAIN (Resource temporarily unavailable) 18:45:56.190442 setsockopt(1, SOL_TCP, TCP_CORK, [0], 4) = 0 18:45:56.190492 gettimeofday({1286457356, 190510}, NULL) = 0 18:45:56.190540 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}], 4, 4075) = 1 ([{fd=1, revents=POLLOUT}]) 18:45:56.394306 gettimeofday({1286457356, 394338}, {4294966966, 0}) = 0 18:45:56.394394 write(1, "gAoAKACgAoAKACgAoAKACgAoAKACgAoA"..., 2881) = 2881 18:45:56.394