Stefan Förster
2009-Aug-03 08:01 UTC
[Dovecot] Performance problem with STATUS after upgrade (1.0.15 -> 1.2.2)
Hello list,
after upgrading dovecot from 1.0.15 to 1.2.2 (and carefully reading
through the upgrading notes in the wiki), I got sieve, quota and fts
up and running, but I'm now suffering some kind of performance problem
with the STATUS command.
Symptoms: Reading mail on the IMAP server itself with "mutt", no
TLS/SSL,
connected through loopback interface. Whenever I idle a bit and then hit any
key thereafter, for example to change into another mailbox, mutt will send a
number of "STATUS" commands:
#
T 127.0.0.1:53604 -> 127.0.0.1:143 [AP]
DONE..a0070 STATUS "postfix-buch" (UIDNEXT UIDVALIDITY UNSEEN
RECENT)..a0071 STATUS "postfix-users" (UIDNEXT UIDVALIDITY UNSEEN
RECENT)..a0072 STATUS "Trash" (UIDNEXT UIDVALIDITY UNSEEN
RECENT)..a0073 STATUS "Sent" (UIDNEXT UIDVALID
ITY UNSEEN RECENT)..a0074 STATUS "mailman-users" (UIDNEXT
UIDVALIDITY UNSEEN RECENT)..a0075 STATUS "mailman-developers" (UIDNEXT
UIDVALIDITY UNSEEN RECENT)..a0076 STATUS "de-postfix-users" (UIDNEXT
UIDVALIDITY UNSEEN RECENT)..a0077
STATUS "amavis-users" (UIDNEXT UIDVALIDITY UNSEEN RECENT)..a0078
STATUS "spam" (UIDNEXT UIDVALIDITY UNSEEN RECENT)..a0079 STATUS
"localreports" (UIDNEXT UIDVALIDITY UNSEEN RECENT)..a0080 STATUS
"Drafts" (UIDNEXT UIDVALIDITY UNSEEN R
ECENT)..a0081 STATUS "exim-users" (UIDNEXT UIDVALIDITY UNSEEN
RECENT)..
#
(The whole conversation is available as:
http://www.incertum.net/~cite/dovecot-snoop.log)
Those commands take almost one(!) second to complete. I've used strace to
capture what happens and made the results available at
http://www.incertum.net/~cite/imap.log.
With 1.0.15, I never noticed this kind of delay, and reading mail
feels really sluggish at the moment. Is there any way to improve
performance?
Configuration data:
Filesystem mounted to /export/vmailboxes is an ext3:
# tune2fs -l /dev/rootvg/mailhome_lv | grep "^Filesystem features"
Filesystem features: has_journal resize_inode dir_index filetype
needs_recovery sparse_super large_file
(needs_recovery is set because the filesystem is mounted, I umounted
it, did fsck -Dfy and it didn't display that "feature" when
unmounted).
dovecot -n (also available as:
http://www.incertum.net/~cite/dovecot-n.log):
# 1.2.2: /etc/dovecot/dovecot.conf
# OS: Linux 2.6.26-2-amd64 x86_64 Debian 5.0.2
log_timestamp: %Y-%m-%d %H:%M:%S
protocols: imap imaps managesieve
listen(default): *:143
listen(imap): *:143
listen(managesieve): *
ssl_listen(default): *:993
ssl_listen(imap): *:993
ssl_listen(managesieve):
ssl_cert_file: /etc/ssl/owncerts/mail_incertum_net.crt
ssl_key_file: /etc/ssl/private/mail_incertum_net.key
login_dir: /var/run/dovecot/login
login_executable(default): /usr/lib/dovecot/imap-login
login_executable(imap): /usr/lib/dovecot/imap-login
login_executable(managesieve): /usr/lib/dovecot/managesieve-login
verbose_proctitle: yes
mail_privileged_group: vmail
mail_location: maildir:~/Maildir
mbox_write_locks: fcntl dotlock
mail_executable(default): /usr/lib/dovecot/imap
mail_executable(imap): /usr/lib/dovecot/imap
mail_executable(managesieve): /usr/lib/dovecot/managesieve
mail_process_size: 1024
mail_plugins(default): quota imap_quota fts fts_squat
mail_plugins(imap): quota imap_quota fts fts_squat
mail_plugins(managesieve):
mail_plugin_dir(default): /usr/lib/dovecot/modules/imap
mail_plugin_dir(imap): /usr/lib/dovecot/modules/imap
mail_plugin_dir(managesieve): /usr/lib/dovecot/modules/managesieve
lda:
postmaster_address: postmaster at incertum.net
hostname: mail.incertum.net
mail_plugins: quota sieve
auth_socket_path: /var/run/dovecot/auth-master
auth default:
mechanisms: plain login cram-md5
passdb:
driver: sql
args: /etc/dovecot/dovecot-sql.conf
userdb:
driver: sql
args: /etc/dovecot/dovecot-sql.conf
socket:
type: listen
client:
path: /var/spool/postfix/private/auth
mode: 432
user: postfix
group: sasl
master:
path: /var/run/dovecot/auth-master
mode: 384
user: vmail
group: vmail
plugin:
quota: maildir:User quota
quota_warning: storage=80%% /usr/local/bin/quota-warning.sh 80
quota_warning: storage=95%% /usr/local/bin/quota-warning.sh 95
sieve: ~/.dovecot.sieve
sieve_storage: ~/sieve
sieve_extensions: +imapflags
fts: squat
fts_squat: partial=4 full=10
SQL-Configuration:
# grep -v '^ *\(#.*\)\?$' dovecot-sql.conf
driver = pgsql
connect = hostaddr=333.33.33.3 port=5432 dbname=secret
user=secret password=secret sslmode=require
default_pass_scheme = PLAIN
password_query = SELECT login AS user, password FROM virtual_user_maps
WHERE login IN ('%u', '%n')
user_query = SELECT vum.uid, vum.gid, ('*:storage=' ||
vum.quota_kbytes || 'k') AS quota_rule, ('/export/vmailboxes/'
||
SUBSTR(vum.login, 1, 1) || '/' || vum.login) AS home FROM
virtual_mailbox_domains AS vmd LEFT JOIN virtual_mailbox_maps AS vmm
ON (vmd.id = vmm.domain) LEFT JOIN virtual_user_maps AS vum ON
(vmm.login = vum.id) WHERE ((vmm.localpart = '%n' AND
vmd.name='%d')
OR (vum.login = '%u')) AND vum.active
Memory:
# free -m
total used free shared buffers cached
Mem: 3952 3003 949 0 226 1036
-/+ buffers/cache: 1740 2211
Swap: 7812 5 7807
The version is Debian/unstable's 1.2.2, available at
http://packages.debian.org/sid/dovecot-common, I've made a backport to
Debian/stable.
Any help/insights are really appreciated.
Cheers
Stefan
Stefan Förster
2009-Aug-03 08:45 UTC
[Dovecot] Performance problem with STATUS after upgrade (1.0.15 -> 1.2.2)
Quick follwup to myself: * Stefan F?rster <cite+dovecot-users at incertum.net>:> (The whole conversation is available as: http://www.incertum.net/~cite/dovecot-snoop.log)[...]> dovecot -n (also available as: http://www.incertum.net/~cite/dovecot-n.log):I've noticed some people trying to access this URLs with the enclosing ")" still in place. Of course, the URLs are: http://www.incertum.net/~cite/dovecot-snoop.log http://www.incertum.net/~cite/dovecot-n.log And in case that it wasn't clear: This... http://www.incertum.net/~cite/imap.log ...is the "strace" output.> Any help/insights are really appreciated.Cheers Stefan
Stefan Förster
2009-Aug-03 12:08 UTC
[Dovecot] Performance problem with STATUS after upgrade (1.0.15 -> 1.2.2)
Another follow-up on my first posting: * Stefan F?rster <cite+dovecot-users at incertum.net>:> Those commands take almost one(!) second to complete. I've used strace to > capture what happens and made the results available at > http://www.incertum.net/~cite/imap.log.Comaring this to a 1.0.15, the main difference seems to be that the "dovecot-uidlist" file is rewritten every time I issue a "STATUS" command. Here's what 1.0.15 does: read(0, "a0071 STATUS \"postfix-users\" (UID"..., 4072) = 66 setsockopt(1, SOL_TCP, TCP_CORK, [1], 4) = 0 stat("/export/vmailboxes/c/cite/Maildir/.postfix-users", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0 stat("/export/vmailboxes/c/cite/Maildir/.postfix-users/cur", {st_mode=S_IFDIR|0700, st_size=1650688, ...}) = 0 stat("/export/vmailboxes/c/cite/Maildir/.postfix-users/new", {st_mode=S_IFDIR|0700, st_size=36864, ...}) = 0 stat("/export/vmailboxes/c/cite/Maildir/.postfix-users/tmp", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0 stat("/export/vmailboxes/c/cite/Maildir/.postfix-users", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0 stat("/export/vmailboxes/c/cite/Maildir/.postfix-users/dovecot-shared", 0x7fff35082530) = -1 ENOENT (No such file or directory) brk(0x8b0000) = 0x8b0000 gettimeofday({1249300019, 466489}, NULL) = 0 open("/export/vmailboxes/c/cite/Maildir/.postfix-users/dovecot.index", O_RDWR) = 7 alarm(120) = 0 fcntl(7, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}) = 0 alarm(0) = 120 fstat(7, {st_mode=S_IFREG|0600, st_size=289344, ...}) = 0 mmap(NULL, 289344, PROT_READ|PROT_WRITE, MAP_SHARED, 7, 0) = 0x7fde2d02c000 open("/export/vmailboxes/c/cite/Maildir/.postfix-users/dovecot.index.log", O_RDWR) = 8 fstat(8, {st_mode=S_IFREG|0600, st_size=296440, ...}) = 0 pread(8, "\1\0\30\0Y\315vJ\1\0\0\0\0\0\0\0\0\0\0\0Y\315vJ"..., 24, 0) = 24 fcntl(7, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0 access("/export/vmailboxes/c/cite/Maildir/.postfix-users/cur", W_OK) = 0 stat("/export/vmailboxes/c/cite/Maildir/.postfix-users/new", {st_mode=S_IFDIR|0700, st_size=36864, ...}) = 0 stat("/export/vmailboxes/c/cite/Maildir/.postfix-users/cur", {st_mode=S_IFDIR|0700, st_size=1650688, ...}) = 0 fstat(7, {st_mode=S_IFREG|0600, st_size=289344, ...}) = 0 stat("/export/vmailboxes/c/cite/Maildir/.postfix-users/dovecot.index", {st_mode=S_IFREG|0600, st_size=289344, ...}) = 0 alarm(120) = 0 fcntl(7, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}) = 0 alarm(0) = 120 fstat(8, {st_mode=S_IFREG|0600, st_size=296440, ...}) = 0 mmap(NULL, 296440, PROT_READ, MAP_SHARED, 8, 0) = 0x7fde2cfe3000 madvise(0x7fde2cfe3000, 296440, MADV_SEQUENTIAL) = 0 fcntl(7, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0 gettimeofday({1249300019, 471527}, NULL) = 0 write(1, "* STATUS \"postfix-users\" (RECENT "..., 111) = 111 setsockopt(1, SOL_TCP, TCP_CORK, [0], 4) = 0 gettimeofday({1249300019, 471961}, NULL) = 0 epoll_wait(4, <unfinished ...> As you can see, dovecot-uidlist istn recreated. Is this intended behaviour, some unfortunate side effect of mounting the partition with "relatime" or something completely different, perhaps something about my plugin (quota, sieve, fts)? Ciao Stefan -- Stefan F?rster http://www.incertum.net/ Public Key: 0xBBE2A9E9 UNIX *is* user-friendly; it's just picky about its friends."
Timo Sirainen
2009-Aug-03 16:49 UTC
[Dovecot] Performance problem with STATUS after upgrade (1.0.15 -> 1.2.2)
On Mon, 2009-08-03 at 10:01 +0200, Stefan F?rster wrote:> after upgrading dovecot from 1.0.15 to 1.2.2 (and carefully reading > through the upgrading notes in the wiki), I got sieve, quota and fts > up and running, but I'm now suffering some kind of performance problem > with the STATUS command.Thanks, fixed: http://hg.dovecot.org/dovecot-1.2/rev/25c9df95fda6 I guess this could also explain the other v1.2 performance complaint I remember hearing about. Probably time for v1.2.3. -------------- next part -------------- A non-text attachment was scrubbed... Name: signature.asc Type: application/pgp-signature Size: 197 bytes Desc: This is a digitally signed message part URL: <http://dovecot.org/pipermail/dovecot/attachments/20090803/7e7371dd/attachment-0002.bin>