[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@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@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.«
Hello,
*ping*
Really no one able to help with the issue below?
Best, Nikolaus
Nikolaus Rath <Nikolaus@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@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@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.«
Hmh. Can you try if this patch fixes it? http://hg.dovecot.org/dovecot-2.2/rev/c0236d1c4a04
On 11.12.2013, at 19.10, Nikolaus Rath <Nikolaus@rath.org> wrote:
Hello,
*ping*
Really no one able to help with the issue below?
Best, Nikolaus
Nikolaus Rath <Nikolaus@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@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@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.«
Am 11.12.2013 18:39, schrieb Timo Sirainen:
Hmh. Can you try if this patch fixes it? http://hg.dovecot.org/dovecot-2.2/rev/c0236d1c4a04
patch is for 2.2.x , so he has to do total upgrade
On 11.12.2013, at 19.10, Nikolaus Rath <Nikolaus@rath.org> wrote:
Hello,
*ping*
Really no one able to help with the issue below?
Best, Nikolaus
Nikolaus Rath <Nikolaus@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@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@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.«
Best Regards MfG Robert Schetterer
-- [*] sys4 AG
http://sys4.de, +49 (89) 30 90 46 64 Franziskanerstraße 15, 81669 München
Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263 Vorstand: Patrick Ben Koetter, Axel von der Ohe, Marc Schiffbauer Aufsichtsratsvorsitzender: Florian Kirstein
On 11.12.2013, at 20.28, Robert Schetterer <rs@sys4.de> wrote:
Am 11.12.2013 18:39, schrieb Timo Sirainen:
Hmh. Can you try if this patch fixes it? http://hg.dovecot.org/dovecot-2.2/rev/c0236d1c4a04
patch is for 2.2.x , so he has to do total upgrade
It applies to v2.1 as well.
Hi,
I've applied the patch and will report back if the problem occurs again. Thanks!
Best, Nikolaus
Timo Sirainen <tss@iki.fi> writes:
Hmh. Can you try if this patch fixes it? http://hg.dovecot.org/dovecot-2.2/rev/c0236d1c4a04
On 11.12.2013, at 19.10, Nikolaus Rath <Nikolaus@rath.org> wrote:
Hello,
*ping*
Really no one able to help with the issue below?
Best, Nikolaus
Nikolaus Rath <Nikolaus@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@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@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.«
-- 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.«
Am 11.12.2013 18:10, schrieb Nikolaus Rath:
Hello,
*ping*
backping upgrade to 2.1.17, perhaps bug is allready fixed
Really no one able to help with the issue below?
Best, Nikolaus
Nikolaus Rath <Nikolaus@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@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@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.«
Best Regards MfG Robert Schetterer
-- [*] sys4 AG
http://sys4.de, +49 (89) 30 90 46 64 Franziskanerstraße 15, 81669 München
Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263 Vorstand: Patrick Ben Koetter, Axel von der Ohe, Marc Schiffbauer Aufsichtsratsvorsitzender: Florian Kirstein
participants (3)
-
Nikolaus Rath
-
Robert Schetterer
-
Timo Sirainen