Nikolaus Rath
2013-Dec-07 03:11 UTC
[Dovecot] dovecot-imapd eating 100% cpu every once in a while
Hello,
About once or twice a week, dovecot's imap-login process on my system
seems gets out of control, eating 100% CPU for about 2 hours. Afterwards
everything seems to go back to normal.
I am using Dovecot 2.1.7 on a 64 bit Debian wheezy system.
When running gdb on the process in this stage, I get the following
traceback:
#0 0x00007fcba50c5a90 in read () from /lib/x86_64-linux-gnu/libc.so.6
#1 0x00007fcba4aa01aa in ?? () from
/usr/lib/x86_64-linux-gnu/libcrypto.so.1.0.0
#2 0x00007fcba4a9df09 in BIO_read () from
/usr/lib/x86_64-linux-gnu/libcrypto.so.1.0.0
#3 0x00007fcba4dbac8c in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0
#4 0x00007fcba4dbbe75 in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0
#5 0x00007fcba4dbd8d0 in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0
#6 0x00007fcba4dad07a in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0
#7 0x00007fcba4db143b in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0
#8 0x00007fcba5622b61 in ssl_handshake (proxy=0x7fcba7870bb0) at
ssl-proxy-openssl.c:465
#9 ssl_step (proxy=0x7fcba7870bb0) at ssl-proxy-openssl.c:528
#10 0x00007fcba53d2016 in io_loop_call_io (io=0x7fcba786fc80) at ioloop.c:379
#11 0x00007fcba53d2cc7 in io_loop_handler_run (ioloop=ioloop at
entry=0x7fcba778c6e0)
at ioloop-epoll.c:213
#12 0x00007fcba53d1a28 in io_loop_run (ioloop=0x7fcba778c6e0) at ioloop.c:398
#13 0x00007fcba53be483 in master_service_run (service=0x7fcba778c590,
callback=callback at entry=0x7fcba5620100 <client_connected>) at
master-service.c:544
#14 0x00007fcba562079e in login_binary_run (binary=<optimized out>,
argc=1, argv=0x7fcba778c370)
at main.c:406
#15 0x00007fcba5015ead in __libc_start_main () from
/lib/x86_64-linux-gnu/libc.so.6
#16 0x00007fcba5a52b2d in _start ()
strace -tt says:
16:14:19.693378 gettimeofday({1381421659, 693415}, NULL) = 0
16:14:19.693490 time(NULL) = 1381421659
16:14:19.693588 read(18, 0x7fcba7876a43, 5) = -1 EAGAIN (Resource temporarily
unavailable)
16:14:19.693688 epoll_wait(14, {{EPOLLOUT, {u32=2810463600,
u64=140512665552240}}}, 10, 4294967295) = 1
16:14:19.693796 gettimeofday({1381421659, 693823}, NULL) = 0
16:14:19.693890 time(NULL) = 1381421659
16:14:19.693984 read(18, 0x7fcba7876a43, 5) = -1 EAGAIN (Resource temporarily
unavailable)
16:14:19.694084 epoll_wait(14, {{EPOLLOUT, {u32=2810463600,
u64=140512665552240}}}, 10, 4294967295) = 1
16:14:19.694177 gettimeofday({1381421659, 694203}, NULL) = 0
16:14:19.694269 time(NULL) = 1381421659
16:14:19.694399 read(18, 0x7fcba7876a43, 5) = -1 EAGAIN (Resource temporarily
unavailable)
16:14:19.694563 epoll_wait(14, {{EPOLLOUT, {u32=2810463600,
u64=140512665552240}}}, 10, 4294967295) = 1
16:14:19.694706 gettimeofday({1381421659, 694757}, NULL) = 0
16:14:19.694849 time(NULL) = 1381421659
16:14:19.694976 read(18, 0x7fcba7876a43, 5) = -1 EAGAIN (Resource temporarily
unavailable)
16:14:19.695091 epoll_wait(14, {{EPOLLOUT, {u32=2810463600,
u64=140512665552240}}}, 10, 4294967295) = 1
16:14:19.695201 gettimeofday({1381421659, 695230}, NULL) = 0
16:14:19.695300 time(NULL) = 1381421659
16:14:19.695420 read(18, 0x7fcba7876a43, 5) = -1 EAGAIN (Resource temporarily
unavailable)
16:14:19.695555 epoll_wait(14, <unfinished ...>
dovecot -n output is:
# 2.1.7: /etc/dovecot/dovecot.conf
# OS: Linux 3.2.0-4-amd64 x86_64 Debian 7.2 ext3
first_valid_uid = 8
last_valid_uid = 8
mail_access_groups = spamd-clients
mail_gid = mail
mail_location = mdbox:/var/spool/mail/%n/mdbox
mail_plugins = fts quota fts_lucene
mail_uid = mail
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character
vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy
include variables body enotify environment mailbox date ihave
namespace inbox {
inbox = yes
location =
mailbox Drafts {
special_use = \Drafts
}
mailbox Sent {
special_use = \Sent
}
mailbox "Sent Messages" {
special_use = \Sent
}
mailbox Spam {
special_use = \Junk
}
mailbox Trash {
special_use = \Trash
}
prefix =
}
passdb {
args = scheme=SHA512-CRYPT username_format=%n /etc/dovecot/users
driver = passwd-file
}
plugin {
antispam_backend = pipe
antispam_pipe_program = /usr/local/bin/spamc_wrapper
antispam_pipe_program_notspam_args = -L;ham
antispam_pipe_program_spam_args = -L;spam
antispam_spam = Spam
antispam_trash = Trash;Papierkorb
fts = lucene
fts_lucene = whitespace_chars=@.
quota = dict:User quota::file:%h/quota
quota_rule = *:storage=1G
quota_rule2 = Trash:storage=+100M
sieve = ~/.dovecot.sieve
sieve_dir = ~/sieve
}
protocols = " imap lmtp sieve"
service auth {
unix_listener auth-client {
mode = 0600
user = Debian-exim
}
}
service lmtp {
inet_listener lmtp {
address = 127.0.0.1
port = 2003
}
}
service managesieve-login {
inet_listener sieve {
port = 4190
}
process_min_avail = 0
service_count = 1
}
ssl_cert = </etc/dovecot/dovecot.pem
ssl_key = </etc/dovecot/private/dovecot.pem
userdb {
args = username_format=%n /etc/dovecot/users
driver = passwd-file
override_fields = home=/var/spool/mail/%n
}
protocol lmtp {
mail_plugins = fts quota fts_lucene sieve
}
protocol lda {
mail_plugins = fts quota fts_lucene sieve
}
protocol imap {
mail_max_userip_connections = 50
mail_plugins = fts quota fts_lucene imap_quota antispam
}
Is this a bug in dovecot, or am I doing something wrong? Is there
something I can do to debug this further?
Best,
Nikolaus
--
Encrypted emails preferred.
PGP fingerprint: 5B93 61F8 4EA2 E279 ABF6 02CF A9AD B7F8 AE4E 425C
?Time flies like an arrow, fruit flies like a Banana.?
Nikolaus Rath
2013-Dec-11 17:10 UTC
[Dovecot] dovecot-imapd eating 100% cpu every once in a while
Hello, *ping* Really no one able to help with the issue below? Best, Nikolaus Nikolaus Rath <Nikolaus at rath.org> writes:> Hello, > > About once or twice a week, dovecot's imap-login process on my system > seems gets out of control, eating 100% CPU for about 2 hours. Afterwards > everything seems to go back to normal. > > I am using Dovecot 2.1.7 on a 64 bit Debian wheezy system. > > When running gdb on the process in this stage, I get the following > traceback: > > #0 0x00007fcba50c5a90 in read () from /lib/x86_64-linux-gnu/libc.so.6 > #1 0x00007fcba4aa01aa in ?? () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.0.0 > #2 0x00007fcba4a9df09 in BIO_read () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.0.0 > #3 0x00007fcba4dbac8c in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0 > #4 0x00007fcba4dbbe75 in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0 > #5 0x00007fcba4dbd8d0 in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0 > #6 0x00007fcba4dad07a in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0 > #7 0x00007fcba4db143b in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0 > #8 0x00007fcba5622b61 in ssl_handshake (proxy=0x7fcba7870bb0) at ssl-proxy-openssl.c:465 > #9 ssl_step (proxy=0x7fcba7870bb0) at ssl-proxy-openssl.c:528 > #10 0x00007fcba53d2016 in io_loop_call_io (io=0x7fcba786fc80) at ioloop.c:379 > #11 0x00007fcba53d2cc7 in io_loop_handler_run (ioloop=ioloop at entry=0x7fcba778c6e0) > at ioloop-epoll.c:213 > #12 0x00007fcba53d1a28 in io_loop_run (ioloop=0x7fcba778c6e0) at ioloop.c:398 > #13 0x00007fcba53be483 in master_service_run (service=0x7fcba778c590, > callback=callback at entry=0x7fcba5620100 <client_connected>) at master-service.c:544 > #14 0x00007fcba562079e in login_binary_run (binary=<optimized out>, argc=1, argv=0x7fcba778c370) > at main.c:406 > #15 0x00007fcba5015ead in __libc_start_main () from /lib/x86_64-linux-gnu/libc.so.6 > #16 0x00007fcba5a52b2d in _start () > > strace -tt says: > > 16:14:19.693378 gettimeofday({1381421659, 693415}, NULL) = 0 > 16:14:19.693490 time(NULL) = 1381421659 > 16:14:19.693588 read(18, 0x7fcba7876a43, 5) = -1 EAGAIN (Resource temporarily unavailable) > 16:14:19.693688 epoll_wait(14, {{EPOLLOUT, {u32=2810463600, u64=140512665552240}}}, 10, 4294967295) = 1 > 16:14:19.693796 gettimeofday({1381421659, 693823}, NULL) = 0 > 16:14:19.693890 time(NULL) = 1381421659 > 16:14:19.693984 read(18, 0x7fcba7876a43, 5) = -1 EAGAIN (Resource temporarily unavailable) > 16:14:19.694084 epoll_wait(14, {{EPOLLOUT, {u32=2810463600, u64=140512665552240}}}, 10, 4294967295) = 1 > 16:14:19.694177 gettimeofday({1381421659, 694203}, NULL) = 0 > 16:14:19.694269 time(NULL) = 1381421659 > 16:14:19.694399 read(18, 0x7fcba7876a43, 5) = -1 EAGAIN (Resource temporarily unavailable) > 16:14:19.694563 epoll_wait(14, {{EPOLLOUT, {u32=2810463600, u64=140512665552240}}}, 10, 4294967295) = 1 > 16:14:19.694706 gettimeofday({1381421659, 694757}, NULL) = 0 > 16:14:19.694849 time(NULL) = 1381421659 > 16:14:19.694976 read(18, 0x7fcba7876a43, 5) = -1 EAGAIN (Resource temporarily unavailable) > 16:14:19.695091 epoll_wait(14, {{EPOLLOUT, {u32=2810463600, u64=140512665552240}}}, 10, 4294967295) = 1 > 16:14:19.695201 gettimeofday({1381421659, 695230}, NULL) = 0 > 16:14:19.695300 time(NULL) = 1381421659 > 16:14:19.695420 read(18, 0x7fcba7876a43, 5) = -1 EAGAIN (Resource temporarily unavailable) > 16:14:19.695555 epoll_wait(14, <unfinished ...> > > dovecot -n output is: > > # 2.1.7: /etc/dovecot/dovecot.conf > # OS: Linux 3.2.0-4-amd64 x86_64 Debian 7.2 ext3 > first_valid_uid = 8 > last_valid_uid = 8 > mail_access_groups = spamd-clients > mail_gid = mail > mail_location = mdbox:/var/spool/mail/%n/mdbox > mail_plugins = fts quota fts_lucene > mail_uid = mail > managesieve_notify_capability = mailto > managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date ihave > namespace inbox { > inbox = yes > location = > mailbox Drafts { > special_use = \Drafts > } > mailbox Sent { > special_use = \Sent > } > mailbox "Sent Messages" { > special_use = \Sent > } > mailbox Spam { > special_use = \Junk > } > mailbox Trash { > special_use = \Trash > } > prefix = > } > passdb { > args = scheme=SHA512-CRYPT username_format=%n /etc/dovecot/users > driver = passwd-file > } > plugin { > antispam_backend = pipe > antispam_pipe_program = /usr/local/bin/spamc_wrapper > antispam_pipe_program_notspam_args = -L;ham > antispam_pipe_program_spam_args = -L;spam > antispam_spam = Spam > antispam_trash = Trash;Papierkorb > fts = lucene > fts_lucene = whitespace_chars=@. > quota = dict:User quota::file:%h/quota > quota_rule = *:storage=1G > quota_rule2 = Trash:storage=+100M > sieve = ~/.dovecot.sieve > sieve_dir = ~/sieve > } > protocols = " imap lmtp sieve" > service auth { > unix_listener auth-client { > mode = 0600 > user = Debian-exim > } > } > service lmtp { > inet_listener lmtp { > address = 127.0.0.1 > port = 2003 > } > } > service managesieve-login { > inet_listener sieve { > port = 4190 > } > process_min_avail = 0 > service_count = 1 > } > ssl_cert = </etc/dovecot/dovecot.pem > ssl_key = </etc/dovecot/private/dovecot.pem > userdb { > args = username_format=%n /etc/dovecot/users > driver = passwd-file > override_fields = home=/var/spool/mail/%n > } > protocol lmtp { > mail_plugins = fts quota fts_lucene sieve > } > protocol lda { > mail_plugins = fts quota fts_lucene sieve > } > protocol imap { > mail_max_userip_connections = 50 > mail_plugins = fts quota fts_lucene imap_quota antispam > } > > > Is this a bug in dovecot, or am I doing something wrong? Is there > something I can do to debug this further? > > > Best, > Nikolaus > > -- > Encrypted emails preferred. > PGP fingerprint: 5B93 61F8 4EA2 E279 ABF6 02CF A9AD B7F8 AE4E 425C > > ?Time flies like an arrow, fruit flies like a Banana.?-- Encrypted emails preferred. PGP fingerprint: 5B93 61F8 4EA2 E279 ABF6 02CF A9AD B7F8 AE4E 425C ?Time flies like an arrow, fruit flies like a Banana.?