[Dovecot] 2.0.beta3 imapd running hot

[Bernhard Schmidt]

Hi,

since a couple of weeks I occasionally have an imapd going crazy on me,
using up 100% CPU. Current revision is 10962

29865 vmail     20   0 47820 3296 1708 R 99.7  0.9 131:07.85 imap

vmail    29865 86.1  0.8  47820  3296 ?        R    Mar20 131:20
dovecot/imap [berni 2001:a60:f001:1:219:66ff:fe8b:a6e IDLE

strace -p <pid> shows a repeating pattern of

epoll_wait(8, {{EPOLLOUT, {u32=36560672, u64=36560672}}}, 5, 4872) = 1
gettimeofday({1269133967, 495298}, NULL) = 0
gettimeofday({1269133967, 495333}, NULL) = 0
gettimeofday({1269133967, 495370}, NULL) = 0

with the last argument of epoll_wait (4872) slowly decrementing and then
wrapping around to ~30k.

Attaching gdb shows the following backtrace:

(gdb) bt full
#0  array_idx_i (ioloop=0x22bd5f0) at array.h:189
No locals.
#1  io_loop_handler_run (ioloop=0x22bd5f0) at ioloop-epoll.c:188
        ctx = 0x22bd800
        event = <value optimized out>
        list = <value optimized out>
        io = <value optimized out>
        tv = {tv_sec = 26, tv_usec = 307176}
        t_id = 2
        msecs = 26308
        ret = 1
        i = <value optimized out>
        call = <value optimized out>
#2  0x00007f8f682bc8e8 in io_loop_run (ioloop=0x22bd5f0) at ioloop.c:350
No locals.
#3  0x00007f8f682acd63 in master_service_run (service=0x22bd4c0,
callback=0x6590) at master-service.c:486
No locals.
#4  0x0000000000418551 in main (argc=1, argv=0x22bd3a0) at main.c:313
        set_roots = {0x41b840, 0x0}
        service_flags = <value optimized out>
        storage_service_flags = MAIL_STORAGE_SERVICE_FLAG_DISALLOW_ROOT
        postlogin_socket_path = 0x0
(gdb) c
Continuing.
^C
Program received signal SIGINT, Interrupt.
0x00007fffed1ff9ad in gettimeofday ()
(gdb) bt full
#0  0x00007fffed1ff9ad in gettimeofday ()
No symbol table info available.
#1  0x00007f8f6795f02a in gettimeofday () from /lib/libc.so.6
No symbol table info available.
#2  0x00007f8f682bcb39 in io_loop_handle_timeouts_real
(ioloop=0x22bd5f0) at ioloop.c:291
        item = <value optimized out>
        tv = {tv_sec = 0, tv_usec = 36427248}
        tv_call = {tv_sec = 0, tv_usec = 140737170938560}
        t_id = <value optimized out>
#3  io_loop_handle_timeouts (ioloop=0x22bd5f0) at ioloop.c:339
        _data_stack_cur_id = 0
#4  0x00007f8f682bd70e in io_loop_handler_run (ioloop=0x22bd5f0) at
ioloop-epoll.c:180
        ctx = 0x22bd800
        event = <value optimized out>
        list = <value optimized out>
        io = <value optimized out>
        tv = {tv_sec = 28, tv_usec = 267997}
        t_id = 2
        msecs = 28268
        ret = 1
        i = <value optimized out>
        call = <value optimized out>
#5  0x00007f8f682bc8e8 in io_loop_run (ioloop=0x22bd5f0) at ioloop.c:350
No locals.
#6  0x00007f8f682acd63 in master_service_run (service=0x22bd4c0,
callback=0) at master-service.c:486
No locals.
#7  0x0000000000418551 in main (argc=1, argv=0x22bd3a0) at main.c:313
        set_roots = {0x41b840, 0x0}
        service_flags = <value optimized out>
        storage_service_flags = MAIL_STORAGE_SERVICE_FLAG_DISALLOW_ROOT
        postlogin_socket_path = 0x0

doveconf -n:

mail.svr02.mucip.net:~# doveconf -n
# 2.0.beta3: /etc/dovecot/dovecot.conf
# OS: Linux 2.6.33 x86_64 Debian squeeze/sid 
auth_mechanisms = plain login
disable_plaintext_auth = no
listen = 83.170.6.69, 2001:1b10:1000::110:1:1
mail_gid = 5000
mail_location = maildir:%h/:INDEX=/var/cache/dovecot/%1n/%n
mail_uid = 5000
maildir_stat_dirs = yes
maildir_very_dirty_syncs = yes
passdb {
  args = /etc/dovecot/dovecot-ldap.conf
  driver = ldap
}
plugin {
  quota = dict:user::file:%h/dovecot-quota
  quota_rule = *:storage=500M
  sieve = ~/.dovecot.sieve
  sieve_dir = ~/sieve
}
postmaster_address = postmaster at birkenwald.de
protocols = imap pop3 lmtp managesieve
quota_full_tempfail = yes
service auth {
  unix_listener /var/spool/postfix-mailout/private/auth {
    group = postfix
    mode = 0660
    user = postfix
  }
  unix_listener /var/spool/postfix/private/auth {
    group = postfix
    mode = 0660
    user = postfix
  }
  unix_listener auth-userdb {
    group = vmail
    mode = 0660
  }
}
service imap-login {
  inet_listener imap {
    port = 143
  }
  inet_listener imaps {
    port = 993
    ssl = yes
  }
}
service lmtp {
  inet_listener {
    port = 24
  }
}
service managesieve-login {
  inet_listener sieve_deprecated {
    port = 2000
  }
  process_min_avail = 1
}
service pop3-login {
  inet_listener pop3 {
    port = 110
  }
  inet_listener pop3s {
    port = 995
    ssl = yes
  }
}
ssl_cert = </etc/ssl/private/pop3.mucip.net.crt
ssl_key = </etc/ssl/private/pop3.mucip.net.key
userdb {
  args = /etc/dovecot/dovecot-ldap.conf
  driver = ldap
}
verbose_proctitle = yes
protocol pop3 {
  mail_plugins = quota
  pop3_uidl_format = %08Xu%08Xv
}
protocol lmtp {
  mail_plugins = sieve quota
}
protocol lda {
  mail_plugins = sieve quota
}
protocol imap {
  imap_idle_notify_interval = 600 s
  mail_plugins = quota imap_quota zlib imap_zlib
}

At the moment I have two suspects, the imap_zlib plugin and CONDSTORE
(which I recently reenabled in Thunderbird after the fixed version got
deployed). The client is always Thunderbird 3.0.3+, but from different
systems. It does terminate without any error message in the logs when I
exit Thunderbird.

Now testing without zlib...

Bernhard