[Dovecot] Errors on high load
Hi, always when my server is on high load I saw this errors on logs:
curie:~# uptime 10:22:38 up 19 days, 19:19, 2 users, load average: 207.01, 169.27, 94.41
Sep 15 17:00:26 curie dovecot: imap-login: *** glibc detected *** imap-login: malloc(): memory corruption: 0x00000000009f8560 *** Sep 15 17:00:26 curie dovecot: child 24012 (login) killed with signal 6 Sep 15 18:48:36 curie dovecot: auth(default_with_listener): BUG: Authentication client said it's PID 0 Sep 15 18:48:36 curie dovecot: child 24014 (login) killed with signal 11 Sep 16 09:05:19 curie dovecot: imap-login: *** glibc detected *** imap-login: malloc(): memory corruption: 0x00000000008c4bc0 *** Sep 16 09:05:19 curie dovecot: child 24013 (login) killed with signal 6 Sep 16 10:17:14 curie dovecot: imap-login: *** glibc detected *** imap-login: malloc(): memory corruption: 0x000000000098bb30 *** Sep 16 10:17:14 curie dovecot: child 24015 (login) killed with signal 6 Sep 16 10:19:02 curie dovecot: child 24002 (login) killed with signal 6 Sep 16 10:19:02 curie dovecot: managesieve-login: *** glibc detected *** managesieve-login: double free or corruption (!prev): 0x000000000066d700 ***
Sep 16 10:19:18 curie dovecot: Panic: IMAP(geduardo): file maildir-save.c: line 241 (maildir_get_updated_filename): assertion failed: (ctx->keywords_sync_ctx != NULL || mf->keywords_count == 0) Sep 16 10:19:18 curie dovecot: IMAP(geduardo): Raw backtrace: /usr/libexec/dovecot/imap [0x47a7f2] -> /usr/libexec/dovecot/imap [0x47a863] -> /usr/libexec/dovecot/imap [0x479f16] -> /usr/libexec/dovecot/imap [0x43295b] -> /usr/libexec/dovecot/imap(maildir_transaction_save_commit_pre+0x19a) [0x4331ea] -> /usr/libexec/dovecot/imap [0x42d0b7] -> /usr/libexec/dovecot/imap(index_transaction_commit+0x3f) [0x44b16f] -> /usr/lib/dovecot/imap/lib10_quota_plugin.so [0x2b70f72e90d7] -> /usr/libexec/dovecot/imap(cmd_copy+0x344) [0x4181f4] -> /usr/libexec/dovecot/imap(cmd_uid+0x52) [0x41c072] -> /usr/libexec/dovecot/imap [0x41ca4c] -> /usr/libexec/dovecot/imap [0x41cb02] -> /usr/libexec/dovecot/imap [0x41d2cf] -> /usr/libexec/dovecot/imap(client_input+0x63) [0x41d503] -> /usr/libexec/dovecot/imap(io_loop_handler_run+0xf8) [0x481448] -> /usr/libexec/dovecot/imap(io_loop_run+0x1d) [0x4805ad] -> /usr/libexec/dovecot/imap(main+0x3c2) [0x424962] -> /lib/libc.so.6(__libc_start_main+0xe6) [0x2b70f6d9e1a6] -> /usr/libexec/dovecot Sep 16 10:19:18 curie dovecot: child 20481 (imap) killed with signal 6
I have about 1000 users. To me, this is not a problem, nothing strange occurs (except the slowly, but under heavy load this is normal).
But I think this is interesting to developers... :D
Regards.
On Tue, Sep 16, 2008 at 10:37 AM, Charles Marcus CMarcus@media-brokers.com wrote:
On 9/16/2008, Allan Cassaro (allan.cassaro@gmail.com) wrote:
Hi, always when my server is on high load I saw this errors on logs:
doevecot -n output / version info?
Ouch! Sorry! I forgot this...
Dovecot: 1.1.3 with LDAP and sieve/managesieve plugin and postfix as MTA both with virtual users.
dovecot -n
# 1.1.3: /etc/dovecot/dovecot.conf base_dir: /var/run/dovecot/ protocols: imap imaps managesieve listen(default): * listen(imap): * listen(managesieve): *:2000 disable_plaintext_auth: no login_dir: /var/run/dovecot//login login_executable(default): /usr/libexec/dovecot/imap-login login_executable(imap): /usr/libexec/dovecot/imap-login login_executable(managesieve): /usr/libexec/dovecot/managesieve-login login_process_per_connection: no login_process_size: 512 login_processes_count: 10 login_max_connections: 120 max_mail_processes: 1200 first_valid_uid: 1010 last_valid_uid: 1010 mail_uid: vmail mail_gid: vmail mail_location: maildir:~/Maildir mail_cache_fields: flags, date.sent, date.received, size.virtual, size.physical mail_cache_min_mail_count: 30 mailbox_idle_check_interval: 10 mail_drop_priv_before_exec: yes mail_executable(default): /usr/libexec/dovecot/postlogin mail_executable(imap): /usr/libexec/dovecot/postlogin mail_executable(managesieve): /usr/libexec/dovecot/managesieve mail_plugins(default): quota imap_quota acl mail_plugins(imap): quota imap_quota acl mail_plugins(managesieve): mail_plugin_dir(default): /usr/lib/dovecot/imap mail_plugin_dir(imap): /usr/lib/dovecot/imap mail_plugin_dir(managesieve): /usr/lib/dovecot/managesieve managesieve_implementation_string(default): dovecot managesieve_implementation_string(imap): dovecot managesieve_implementation_string(managesieve): Dovecot ManageSieve 1.1 sieve_storage(default): sieve_storage(imap): sieve_storage(managesieve): ~/sieve sieve(default): sieve(imap): sieve(managesieve): ~/.dovecot.sieve namespace: type: public separator: . prefix: Compartilhado. location: maildir:/home/dovecot-shared:INDEX=~/Maildir/index/compartilhado list: yes subscriptions: yes namespace: type: private separator: . prefix: INBOX. inbox: yes list: yes subscriptions: yes auth default_with_listener: mechanisms: plain login cache_size: 512 cache_ttl: 30 cache_negative_ttl: 0 passdb: driver: ldap args: /etc/dovecot/dovecot-ldap.conf userdb: driver: ldap args: /etc/dovecot/dovecot-ldap.conf socket: type: listen client: path: /var/spool/postfix/private/auth mode: 432 user: postfix group: postfix master: path: /var/run/dovecot/auth-master mode: 384 user: vmail group: vmail plugin: sieve: ~/.dovecot.sieve acl: vfile:/etc/dovecot/dovecot-acls quota: maildir quota_rule: *:storage=50MB quota_rule2: Trash:storage=20%% quota_rule3: Spam:storage=10%% quota_warning: storage=95%% /usr/libexec/dovecot/quota_warning.sh %u 95 quota_warning2: storage=80%% /usr/libexec/dovecot/quota_warning.sh %u 80 mail_log_events: delete undelete expunge copy mailbox_delete mailbox_rename mail_log_group_events: mail_log_fields: uid box msgid size
Regards
Although my high load errors with different, the following might help. Once I did the following system tuning, the errors went away (including the infamous backtrace/maildir_transaction...). The following parameters were cranked up (for dovecot,system, & mail) :
open files => 32768 locks => 32768 maxsyslogins => 16384 maxlogins => 4096 max_user_instances => 2048
In RHE, the first four are in limits.conf and the last is in /proc/sys/fs/inotify/max_user_instances. Probably all are not needed (in particular maxlogins) but open files definitely made a different - lsof was showing 24K files for dovecot & mail. My bottleneck was a piece of old network gear and once the traffic settled down open file dropped to 4K (and load from 200 to 0.5)
These might not address your particular problem but system tuning could address the memory corruption error. These settings also got rid of my error messages under low load.
It is also probably worth while to shut the system down and run memory test (i.e. memtest86+ - or if it is under maintenance just get it replaced)
---Jack
Allan Cassaro wrote:
On Tue, Sep 16, 2008 at 10:37 AM, Charles Marcus CMarcus@media-brokers.com wrote:
On 9/16/2008, Allan Cassaro (allan.cassaro@gmail.com) wrote:
Hi, always when my server is on high load I saw this errors on logs: doevecot -n output / version info?
Ouch! Sorry! I forgot this...
On Tue, 2008-09-16 at 10:34 -0300, Allan Cassaro wrote:
Hi, always when my server is on high load I saw this errors on logs:
curie:~# uptime 10:22:38 up 19 days, 19:19, 2 users, load average: 207.01, 169.27, 94.41
Sep 15 17:00:26 curie dovecot: imap-login: *** glibc detected *** imap-login: malloc(): memory corruption: 0x00000000009f8560 *** Sep 15 17:00:26 curie dovecot: child 24012 (login) killed with signal 6 Sep 15 18:48:36 curie dovecot: auth(default_with_listener): BUG: Authentication client said it's PID 0 Sep 15 18:48:36 curie dovecot: child 24014 (login) killed with signal 11 Sep 16 09:05:19 curie dovecot: imap-login: *** glibc detected *** imap-login: malloc(): memory corruption: 0x00000000008c4bc0 *** Sep 16 09:05:19 curie dovecot: child 24013 (login) killed with signal 6 Sep 16 10:17:14 curie dovecot: imap-login: *** glibc detected *** imap-login: malloc(): memory corruption: 0x000000000098bb30 *** Sep 16 10:17:14 curie dovecot: child 24015 (login) killed with signal 6 Sep 16 10:19:02 curie dovecot: child 24002 (login) killed with signal 6 Sep 16 10:19:02 curie dovecot: managesieve-login: *** glibc detected *** managesieve-login: double free or corruption (!prev):
These are pretty scary. If a user could cause these on will, it could mean a remotely exploitable security hole. But I've not been able to produce such crashes for a long time now and I haven't heard it happening with other people either. You sure the server's memory is OK? Another thing I could blame instead of Dovecot is OpenSSL :)
Sep 16 10:19:18 curie dovecot: Panic: IMAP(geduardo): file maildir-save.c: line 241 (maildir_get_updated_filename): assertion failed: (ctx->keywords_sync_ctx != NULL || mf->keywords_count == 0)
This I fixed recently though: http://hg.dovecot.org/dovecot-1.1/rev/2922490759c9
participants (4)
-
Allan Cassaro
-
Charles Marcus
-
Jack Stewart
-
Timo Sirainen