[Dovecot] mailbox count folders issues
Hello list,
I have one user, which have a lot of folders (not it is 414 without INBOX). When he tries to create one more folder with random name - the folder successfully created, but LIST command invokes out of memory to imap process.
From the logs: Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Panic: data stack: Out of memory when allocating 268435472 bytes Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: *** glibc detected *** imap: double free or corruption (!prev): 0x0812ba00 *** Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: ======= Backtrace: ========= Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: /lib/libc.so.6[0xb7e8a714] Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: /lib/libc.so.6(cfree+0x9c)[0xb7e8bfcc] Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: imap(t_pop+0x7a)[0x80f0a1a] Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: imap(t_pop_check+0xf)[0x80f0b9f] Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: imap[0x80f199d] Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: imap[0x80f2285] Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: imap[0x80f1bd9] Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: imap[0x80f099d] Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: Sending log messages too fast, throttling.. Oct 26 15:26:38 dovecot: Error: child 9497 (imap) killed with signal 6 (core dumps disabled) Oct 26 15:26:39 IMAP(gozhda.a@domain.com): Error: imap[0x80f0e17] Oct 26 15:26:39 IMAP(gozhda.a@domain.com): Error: imap[0x80fccc8] Oct 26 15:26:39 IMAP(gozhda.a@domain.com): Error: imap[0x80efd3a] Oct 26 15:26:39 IMAP(gozhda.a@domain.com): Error: imap(buffer_write+0xd2)[0x80f0242] Oct 26 15:26:39 IMAP(gozhda.a@domain.com): Error: imap(buffer_append+0x26)[0x80f0366] Oct 26 15:26:39 IMAP(gozhda.a@domain.com): Error: imap(mail_transaction_log_append+0x5dc)[0x80d457c] Oct 26 15:26:39 IMAP(gozhda.a@domain.com): Error: imap[0x80c90d9] Oct 26 15:26:39 IMAP(gozhda.a@domain.com): Error: imap(mail_index_sync_commit+0xa5)[0x80cc625] Oct 26 15:26:39 IMAP(gozhda.a@domain.com): Error: /usr/lib/dovecot/imap/lib20_virtual_plugin.so[0xb7de7cee] Oct 26 15:26:39 IMAP(gozhda.a@domain.com): Error: /usr/lib/dovecot/imap/lib20_virtual_plugin.so(virtual_storage_sync_init+0x71c)[0xb7dea7cc] Oct 26 15:26:39 IMAP(gozhda.a@domain.com): Error: imap(mailbox_sync+0x35)[0x80b6335] Oct 26 15:26:40 IMAP(gozhda.a@domain.com): Error: imap(cmd_select_full+0x3d8)[0x8065088] Oct 26 15:26:40 IMAP(gozhda.a@domain.com): Error: imap(cmd_select+0x19)[0x80657e9] Oct 26 15:26:40 IMAP(gozhda.a@domain.com): Error: imap[0x8067a9c] Oct 26 15:26:40 IMAP(gozhda.a@domain.com): Error: imap[0x8067b35] Oct 26 15:26:40 IMAP(gozhda.a@domain.com): Error: imap(client_handle_input+0x2d)[0x8067ced] Oct 26 15:26:40 IMAP(gozhda.a@domain.com): Error: imap(client_input+0x5f)[0x80686af] Oct 26 15:26:40 IMAP(gozhda.a@domain.com): Error: imap(io_loop_handler_run+0xe0)[0x80fae60] Oct 26 15:26:40 IMAP(gozhda.a@domain.com): Error: imap(io_loop_run+0x20)[0x80fa2e0] Oct 26 15:26:40 IMAP(gozhda.a@domain.com): Error: imap(main+0x5ea)[0x807116a] Oct 26 15:26:40 IMAP(gozhda.a@domain.com): Error: /lib/libc.so.6(__libc_start_main+0xe5)[0xb7e35725] Oct 26 15:26:40 IMAP(gozhda.a@domain.com): Error: imap[0x80602b1] Oct 26 15:26:41 IMAP(gozhda.a@domain.com): Error: ======= Memory map: ======== Oct 26 15:26:41 IMAP(gozhda.a@domain.com): Error: 08048000-08129000 r-xp 00000000 08:02 385446 /usr/libexec/dovecot/imap Oct 26 15:26:41 IMAP(gozhda.a@domain.com): Error: 08129000-0812a000 r--p 000e0000 08:02 385446 /usr/libexec/dovecot/imap Oct 26 15:26:41 IMAP(gozhda.a@domain.com): Error: 0812a000-0812c000 rw-p 000e1000 08:02 385446 /usr/libexec/dovecot/imap Oct 26 15:26:41 IMAP(gozhda.a@domain.com): Error: 0812c000-0bbbd000 rw-p 0812c000 00:00 0 [heap] Oct 26 15:26:41 IMAP(gozhda.a@domain.com): Error: 92600000-92621000 rw-p 92600000 00:00 0 Oct 26 15:26:41 IMAP(gozhda.a@domain.com): Error: 92621000-92700000 ---p 92621000 00:00 0 Oct 26 15:26:41 IMAP(gozhda.a@domain.com): Error: b280d000-b2819000 r-xp 00000000 08:02 263779 /usr/lib/gcc/i686-pc-linux-gnu/4.3.4/libgcc_s.so.1 Oct 26 15:26:41 IMAP(gozhda.a@domain.com): Error: b2819000-b281a000 r--p 0000b000 08:02 263779 /usr/lib/gcc/i686-pc-linux-gnu/4.3.4/libgcc_s.so.1 Oct 26 15:26:41 IMAP(gozhda.a@domain.com): Error: b281a000-b281b000 rw-p 0000c000 08:02 263779 /usr/lib/gcc/i686-pc-linux-gnu/4.3.4/libgcc_s.so.1 Oct 26 15:26:41 IMAP(gozhda.a@domain.com): Error: b2822000-b7d88000 rw-p b2822000 00:00 0 Oct 26 15:26:42 IMAP(gozhda.a@domain.com): Error: b7d88000-b7d90000 r--s 00000000 08:11 24109678 /data/mail/domain.com/gozhda.a/data/dovecot.index.cache Oct 26 15:26:42 IMAP(gozhda.a@domain.com): Error: b7d90000-b7d95000 r--s 00000000 08:11 24109800 /data/mail/domain.com/gozhda.a/data/.Supplier.Furniture.Prima Ridhacitra.Inbox/dovecot.index.cache Oct 26 15:26:42 IMAP(gozhda.a@domain.com): Error: b7d95000-b7d9a000 r--s 00000000 08:11 24117515 /data/mail/domain.com/gozhda.a/data/.Supplier.Furniture.Kappa Salotti.Outbox/dovecot.index.cache Oct 26 15:26:42 IMAP(gozhda.a@domain.com): Error: b7d9a000-b7d9f000 r--s 00000000 08:11 24109096 /data/mail/domain.com/gozhda.a/data/.Supplier.Furniture.Keoma Salotti.Inbox/dovecot.index.cache Oct 26 15:26:42 IMAP(gozhda.a@domain.com): Error: b7d9f000-b7da4000 r--s 00000000 08:11 24109729 /data/mail/domain.com/gozhda.a/data/.Supplier.Elements of illumination.Laber Agent.2 Outbox/dovecot.index.cache Oct 26 15:26:42 IMAP(gozhda.a@domain.com): Error: b7da4000-b7da9000 r--s 00000000 08:11 24109097 /data/mail/domain.com/gozhda.a/data/.Supplier.Elements of illumination.Laber Agent.1 Inbox/dovecot.index.cache Oct 26 15:26:42 IMAP(gozhda.a@domain.com): Error: b7da9000-b7dae000 r--s 00000000 08:11 24117749 /data/mail/domain.com/gozhda.a/data/.Structure of Agromat Company.Auto Logistics.1 Inbox/dovecot.index.cache Oct 26 15:26:42 IMAP(gozhda.a@domain.com): Error: b7dae000-b7dbd000 r-xp 00000000 08:02 562992 /lib/libbz2.so.1.0.5 Oct 26 15:26:42 IMAP(gozhda.a@domain.com): Error: b7dbd000-b7dbe000 r--p 0000e000 08:02 562992 /lib/libbz2.so.1.0.5 Oct 26 15:26:42 IMAP(gozhda.a@domain.com): Error: b7dbe000-b7dbf000 rw-p 0000f000 08:02 562992 /lib/libbz2.so.1.0.5 Oct 26 15:26:42 IMAP(gozhda.a@domain.com): Error: b7dbf000-b7dd1000 r-xp 00000000 08:02 562990 /lib/libz.so.1.2.3 Oct 26 15:26:43 IMAP(gozhda.a@domain.com): Error: b7dd1000-b7dd2000 r--p 00011000 08:02 562990 /lib/libz.so.1.2.3 Oct 26 15:26:43 IMAP(gozhda.a@domain.com): Error: b7dd2000-b7dd3000 rw-p 00012000 08:02 562990 /lib/libz.so.1.2.3 Oct 26 15:26:43 IMAP(gozhda.a@domain.com): Error: b7dd7000-b7dda000 r--s 00000000 08:11 24109083 /data/mail/domain.com/gozhda.a/data/dovecot.index.log Oct 26 15:26:43 IMAP(gozhda.a@domain.com): Error: b7dda000-b7ddd000 r-xp 00000000 08:02 269577 /usr/lib/dovecot/lib20_zlib_plugin.so Oct 26 15:26:43 IMAP(gozhda.a@domain.com): Error: b7ddd000-b7dde000 r--p 00002000 08:02 269577 /usr/lib/dovecot/lib20_zlib_plugin.so Oct 26 15:26:43 IMAP(gozhda.a@domain.com): Error: b7dde000-b7ddf000 rw-p 00003000 08:02 269577 /usr/lib/dovecot/lib20_zlib_plugin.so Oct 26 15:26:43 IMAP(gozhda.a@domain.com): Error: b7ddf000-b7dec000 r-xp 00000000 08:02 269941 /usr/lib/dovecot/lib20_virtual_plugin.so Oct 26 15:26:43 IMAP(gozhda.a@domain.com): Error: b7dec000-b7ded000 r--p 0000c000 08:02 269941 /usr/lib/dovecot/lib20_virtual_plugin.so Oct 26 15:26:43 IMAP(gozhda.a@domain.com): Error: b7ded000-b7dee000 rw-p 0000d000 08:02 269941 /usr/lib/dovecot/lib20_virtual_plugin.so Oct 26 15:26:43 IMAP(gozhda.a@domain.com): Error: b7dee000-b7df1000 r-xp 00000000 08:02 272179 /usr/lib/dovecot/lib20_expire_plugin.so Oct 26 15:26:43 IMAP(gozhda.a@domain.com): Error: b7df1000-b7df2000 r--p 00002000 08:02 272179 /usr/lib/dovecot/lib20_expire_plugin.so Oct 26 15:26:44 IMAP(gozhda.a@domain.com): Error: b7df2000-b7df3000 rw-p 00003000 08:02 272179 /usr/lib/dovecot/lib20_expire_plugin.so Oct 26 15:26:44 IMAP(gozhda.a@domain.com): Error: b7df3000-b7df5000 r-xp 00000000 08:02 269836 /usr/lib/dovecot/lib11_trash_plugin.so Oct 26 15:26:44 IMAP(gozhda.a@domain.com): Error: b7df5000-b7df6000 r--p 00001000 08:02 269836 /usr/lib/dovecot/lib11_trash_plugin.so Oct 26 15:26:44 IMAP(gozhda.a@domain.com): Error: b7df6000-b7df7000 rw-p 00002000 08:02 269836 /usr/lib/dovecot/lib11_trash_plugin.so Oct 26 15:26:44 IMAP(gozhda.a@domain.com): Error: b7df7000-b7e04000 r-xp 00000000 08:02 270039 /usr/lib/dovecot/lib10_quota_plugin.so Oct 26 15:26:44 IMAP(gozhda.a@domain.com): Error: b7e04000-b7e05000 r--p 0000c000 08:02 270039 /usr/lib/dovecot/lib10_quota_plugin.so Oct 26 15:26:44 IMAP(gozhda.a@domain.com): Error: b7e05000-b7e06000 rw-p 0000d000 08:02 270039 /usr/lib/dovecot/lib10_quota_plugin.so Oct 26 15:26:44 IMAP(gozhda.a@domain.com): Error: b7e06000-b7e07000 rw-p b7e06000 00:00 0 Oct 26 15:26:44 IMAP(gozhda.a@domain.com): Error: b7e07000-b7e1b000 r-xp 00000000 08:02 562206 /lib/libpthread-2.9.so Oct 26 15:26:44 IMAP(gozhda.a@domain.com): Error: b7e1b000-b7e1c000 r--p 00013000 08:02 562206 /lib/libpthread-2.9.so Oct 26 15:26:44 IMAP(gozhda.a@domain.com): Error: b7e1c000-b7e1d000 rw-p 00014000 08:02 562206 /lib/libpthread-2.9.so Oct 26 15:26:45 IMAP(gozhda.a@domain.com): Error: b7e1d000-b7e1f000 rw-p b7e1d000 00:00 0 Oct 26 15:26:45 IMAP(gozhda.a@domain.com): Error: b7e1f000-b7f5c000 r-xp 00000000 08:02 563472 /lib/libc-2.9.so Oct 26 15:26:45 IMAP(gozhda.a@domain.com): Error: b7f5c000-b7f5e000 r--p 0013d000 08:02 563472 /lib/libc-2.9.so Oct 26 15:26:45 IMAP(gozhda.a@domain.com): Error: b7f5e000-b7f5f000 rw-p 0013f000 08:02 563472 /lib/libc-2.9.so Oct 26 15:26:45 IMAP(gozhda.a@domain.com): Error: b7f5f000-b7f62000 rw-p b7f5f000 00:00 0 Oct 26 15:26:45 IMAP(gozhda.a@domain.com): Error: b7f62000-b7f69000 r-xp 00000000 08:02 563080 /lib/librt-2.9.so Oct 26 15:26:45 IMAP(gozhda.a@domain.com): Error: b7f69000-b7f6a000 r--p 00006000 08:02 563080 /lib/librt-2.9.so Oct 26 15:26:45 IMAP(gozhda.a@domain.com): Error: b7f6a000-b7f6b000 rw-p 00007000 08:02 563080 /lib/librt-2.9.so Oct 26 15:26:45 IMAP(gozhda.a@domain.com): Error: b7f6b000-b7f6d000 r-xp 00000000 08:02 563473 /lib/libdl-2.9.so Oct 26 15:26:45 IMAP(gozhda.a@domain.com): Error: b7f6d000-b7f6e000 r--p 00001000 08:02 563473 /lib/libdl-2.9.so Oct 26 15:26:45 IMAP(gozhda.a@domain.com): Error: b7f6e000-b7f6f000 rw-p 00002000 08:02 563473 /lib/libdl-2.9.so Oct 26 15:26:46 IMAP(gozhda.a@domain.com): Error: b7f6f000-b7f70000 rw-p b7f6f000 00:00 0 Oct 26 15:26:46 IMAP(gozhda.a@domain.com): Error: b7f70000-b7f71000 r-xp 00000000 08:02 269571 /usr/lib/dovecot/lib20_autocreate_plugin.so Oct 26 15:26:46 IMAP(gozhda.a@domain.com): Error: b7f71000-b7f72000 r--p 00000000 08:02 269571 /usr/lib/dovecot/lib20_autocreate_plugin.so Oct 26 15:26:46 IMAP(gozhda.a@domain.com): Error: b7f72000-b7f73000 rw-p 00001000 08:02 269571 /usr/lib/dovecot/lib20_autocreate_plugin.so Oct 26 15:26:46 IMAP(gozhda.a@domain.com): Error: b7f73000-b7f75000 r-xp 00000000 08:02 270032 /usr/lib/dovecot/imap/lib11_imap_quota_plugin.so Oct 26 15:26:46 IMAP(gozhda.a@domain.com): Error: b7f75000-b7f76000 r--p 00001000 08:02 270032 /usr/lib/dovecot/imap/lib11_imap_quota_plugin.so Oct 26 15:26:46 IMAP(gozhda.a@domain.com): Error: b7f76000-b7f77000 rw-p 00002000 08:02 270032 /usr/lib/dovecot/imap/lib11_imap_quota_plugin.so Oct 26 15:26:46 IMAP(gozhda.a@domain.com): Error: b7f77000-b7f93000 r-xp 00000000 08:02 563474 /lib/ld-2.9.so Oct 26 15:26:46 IMAP(gozhda.a@domain.com): Error: b7f93000-b7f94000 r--p 0001c000 08:02 563474 /lib/ld-2.9.so Oct 26 15:26:46 IMAP(gozhda.a@domain.com): Error: b7f94000-b7f95000 rw-p 0001d000 08:02 563474 /lib/ld-2.9.so Oct 26 15:26:46 IMAP(gozhda.a@domain.com): Error: bfb7f000-bfb94000 rw-p bffeb000 00:00 0 [stack] Oct 26 15:26:47 IMAP(gozhda.a@domain.com): Error: ffffe000-fffff000 r-xp 00000000 00:00 0 [vdso] Oct 26 15:26:57 IMAP(gozhda.a@domain.com): Panic: data stack: Out of memory when allocating 268435472 bytes And so on...
I have tried to grow mail_process_size from 256 to 512, but this didn't help. My question - is there some hardcoded limit for mail directories or it's a bug ?
dovecot -n: # 1.2.6: /etc/dovecot/dovecot.conf # OS: Linux 2.6.26-gentoo-r4 i686 Gentoo Base System release 1.12.11.1 log_path: /var/log/dovecot/dovecot-error.log info_log_path: /var/log/dovecot/dovecot.log protocols: imaps managesieve ssl_cert_file: /etc/ssl/dovecot/imaps.crt ssl_key_file: /etc/ssl/dovecot/imaps.key 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_greeting: Server ready. login_processes_count: 20 login_max_processes_count: 512 mail_max_userip_connections(default): 20 mail_max_userip_connections(imap): 20 mail_max_userip_connections(managesieve): 10 first_valid_uid: 8 last_valid_uid: 8 first_valid_gid: 12 last_valid_gid: 12 mail_drop_priv_before_exec: yes mail_executable(default): /usr/libexec/dovecot/imap mail_executable(imap): /usr/libexec/dovecot/imap mail_executable(managesieve): /usr/libexec/dovecot/managesieve mail_plugins(default): quota imap_quota trash expire zlib autocreate virtual mail_plugins(imap): quota imap_quota trash expire zlib autocreate virtual 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 imap_client_workarounds(default): delay-newmail imap_client_workarounds(imap): delay-newmail imap_client_workarounds(managesieve): namespace: type: private separator: / location: maildir:~/data inbox: yes list: yes subscriptions: yes namespace: type: private separator: / prefix: Company/ location: virtual:/var/mail/virtual:INDEX=MEMORY:LAYOUT=maildir++ list: yes lda: postmaster_address: postmaster@domain.com hostname: mail.domain.com mail_plugins: quota trash expire sieve virtual quota_full_tempfail: yes sendmail_path: /usr/sbin/sendmail auth_socket_path: /var/run/dovecot/auth-master log_path: /var/log/dovecot/dovecot-deliver.log info_log_path: /var/log/dovecot/dovecot-deliver.log global_script_path: /etc/dovecot/sieve/default.sieve sieve_global_dir: /etc/dovecot/sieve auth default: mechanisms: plain login default_realm: domain.com cache_size: 10240 cache_negative_ttl: 0 user: dovecot_auth master_user_separator: * worker_max_count: 50 passdb: driver: passwd-file args: /etc/dovecot/passdb/master.pwd master: yes passdb: driver: passwd-file args: /etc/dovecot/passdb/users.pwd passdb: driver: ldap args: /etc/dovecot/dovecot-ldap.conf userdb: driver: prefetch userdb: driver: ldap args: /etc/dovecot/dovecot-userdb-ldap.conf userdb: driver: passwd-file args: /etc/dovecot/passdb/users.pwd socket: type: listen client: path: /var/run/dovecot/auth-client mode: 432 user: mail group: dovecot_auth master: path: /var/run/dovecot/auth-master mode: 384 user: mail group: mail plugin: quota_warning: storage=90%% /etc/dovecot/plugins/quota_warning.sh 90 quota: maildir:Mailbox quota quota_rule: *:storage=500M quota_rule2: Trash:storage=10%% trash: /etc/dovecot/plugins/dovecot-trash.conf expire: Trash 30 Spam 30 expire_dict: proxy::expire autocreate: Drafts autocreate2: Sent autocreate3: Spam autocreate4: Trash autosubscribe: Drafts autosubscribe2: Sent autosubscribe3: Spam autosubscribe4: Trash sieve: ~/.dovecot.sieve sieve_dir: ~/sieve sieve_extensions: +notify sieve_before: /etc/dovecot/sieve/default.sieve dict: expire: sqlite:/etc/dovecot/plugins/expire.conf
On Tue, 2009-10-27 at 09:48 +0200, Nikita Koshikov wrote:
I have one user, which have a lot of folders (not it is 414 without INBOX). When he tries to create one more folder with random name - the folder successfully created, but LIST command invokes out of memory to imap process.
From the logs: Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Panic: data stack: Out of memory when allocating 268435472 bytes Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: *** glibc detected *** imap: double free or corruption (!prev): 0x0812ba00 ***
This is bad. Can you reproduce it easily? Could you cause this crash under valgrind? For example:
protocol imap { mail_executable = /usr/local/bin/imap.sh }
and /usr/local/bin/imap.sh:
#!/bin/sh
if [ $USER = "gozhda.a@domain.com" ]; then exec /usr/bin/valgrind /usr/libexec/dovecot/imap else exec /usr/libexec/dovecot/imap fi
Valgrind will hopefully then log to Dovecot's log what exactly is the problem.
It's anyway related to one of your virtual maiboxes. I suppose you have a virtual mailbox that includes messages from all real mailboxes?
On Tue, 27 Oct 2009 17:50:22 -0400 Timo Sirainen <tss@iki.fi> wrote:
On Tue, 2009-10-27 at 09:48 +0200, Nikita Koshikov wrote:
I have one user, which have a lot of folders (not it is 414 without INBOX). When he tries to create one more folder with random name - the folder successfully created, but LIST command invokes out of memory to imap process.
From the logs: Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Panic: data stack: Out of memory when allocating 268435472 bytes Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: *** glibc detected *** imap: double free or corruption (!prev): 0x0812ba00 ***
This is bad. Can you reproduce it easily? Could you cause this crash under valgrind? For example:
protocol imap { mail_executable = /usr/local/bin/imap.sh }
and /usr/local/bin/imap.sh:
#!/bin/sh
if [ $USER = "gozhda.a@domain.com" ]; then exec /usr/bin/valgrind /usr/libexec/dovecot/imap else exec /usr/libexec/dovecot/imap fi
Valgrind will hopefully then log to Dovecot's log what exactly is the problem.
In attachement full valgrind output for user's session. Steps I perform: 1)Login with admin master password to user's mailbox(from webmail) 2)create new directory 3)try to get directories list
It's anyway related to one of your virtual maiboxes. I suppose you have a virtual mailbox that includes messages from all real mailboxes?
Yes, I have two virtual mailboxes: all - contains all messages favorites - contains flagged letters
But this user didn't subscribe to any of them.
On Wed, 2009-10-28 at 10:39 +0200, Nikita Koshikov wrote:
Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Panic: data stack: Out of memory when allocating 268435472 bytes Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: *** glibc detected *** imap: double free or corruption (!prev): 0x0812ba00 ***
Oh, the double free is because of broken handling of out-of-memory error. http://hg.dovecot.org/dovecot-1.2/rev/acfef2f0fec3 probably fixes that.
It's anyway related to one of your virtual maiboxes. I suppose you have a virtual mailbox that includes messages from all real mailboxes?
Yes, I have two virtual mailboxes: all - contains all messages favorites - contains flagged letters
But this user didn't subscribe to any of them.
Backtrace shows that it crashes while trying to refresh a virtual mailbox.
Hmm. So I guess there's no memory corruption causing this, but I don't really see why it would try to allocate that much memory. 268435472 in hex is 0x10000010, which is an interesting number but doesn't really help much either.
Can you make sure debugging symbols aren't stripped from imap binary (i.e. "file /usr/.../dovecot/imap" says "not stripped", this is the default when compiling Dovecot from sources) and get gdb backtrace? http://dovecot.org/bugreport.html Then I could see exactly where it's crashing and figuring out this would be a lot easier.
On Wed, 28 Oct 2009 14:17:52 -0400 Timo Sirainen <tss@iki.fi> wrote:
On Wed, 2009-10-28 at 10:39 +0200, Nikita Koshikov wrote:
Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Panic: data stack: Out of memory when allocating 268435472 bytes Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: *** glibc detected *** imap: double free or corruption (!prev): 0x0812ba00 ***
Oh, the double free is because of broken handling of out-of-memory error. http://hg.dovecot.org/dovecot-1.2/rev/acfef2f0fec3 probably fixes that.
Sorry, but this patch didn't help.
It's anyway related to one of your virtual maiboxes. I suppose you have a virtual mailbox that includes messages from all real mailboxes?
Yes, I have two virtual mailboxes: all - contains all messages favorites - contains flagged letters
But this user didn't subscribe to any of them.
Backtrace shows that it crashes while trying to refresh a virtual mailbox.
Hmm. So I guess there's no memory corruption causing this, but I don't really see why it would try to allocate that much memory. 268435472 in hex is 0x10000010, which is an interesting number but doesn't really help much either.
268435456 is 256M which is max mail_process_size config setting, maybe this values is in use ?
Can you make sure debugging symbols aren't stripped from imap binary (i.e. "file /usr/.../dovecot/imap" says "not stripped", this is the default when compiling Dovecot from sources) and get gdb backtrace? http://dovecot.org/bugreport.html Then I could see exactly where it's crashing and figuring out this would be a lot easier.
I recompile dovecot binaries with debug symbols, but seemed that gdb backtrace is broken.
root@mail dovecot-1.2.6 0:0 # file /usr/libexec/dovecot/imap /usr/libexec/dovecot/imap: ELF 32-bit LSB executable, Intel 80386, version 1 (SYSV), dynamically linked (uses shared libs), for GNU/Linux 2.6.9, not stripped
root@mail dovecot-1.2.6 0:130 # gdb /usr/libexec/dovecot/imap /data/mail/domain.com/gozhda.a/core GNU gdb 6.8 Copyright (C) 2008 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "i686-pc-linux-gnu"... (no debugging symbols found)
warning: Can't read pathname for load map: Input/output error. Reading symbols from /lib/libdl.so.2...(no debugging symbols found)...done. Loaded symbols for /lib/libdl.so.2 Reading symbols from /lib/librt.so.1...(no debugging symbols found)...done. Loaded symbols for /lib/librt.so.1 Reading symbols from /lib/libc.so.6...(no debugging symbols found)...done. Loaded symbols for /lib/libc.so.6 Reading symbols from /lib/ld-linux.so.2...(no debugging symbols found)...done. Loaded symbols for /lib/ld-linux.so.2 Reading symbols from /lib/libpthread.so.0...(no debugging symbols found)...done. Loaded symbols for /lib/libpthread.so.0 Reading symbols from /usr/lib/dovecot/imap/lib10_quota_plugin.so... (no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib10_quota_plugin.so Reading symbols from /usr/lib/dovecot/imap/lib11_imap_quota_plugin.so...(no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib11_imap_quota_plugin.so Reading symbols from /usr/lib/dovecot/imap/lib11_trash_plugin.so...(no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib11_trash_plugin.so Reading symbols from /usr/lib/dovecot/imap/lib20_autocreate_plugin.so...(no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib20_autocreate_plugin.so Reading symbols from /usr/lib/dovecot/imap/lib20_expire_plugin.so...(no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib20_expire_plugin.so Reading symbols from /usr/lib/dovecot/imap/lib20_virtual_plugin.so... (no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib20_virtual_plugin.so Reading symbols from /usr/lib/dovecot/imap/lib20_zlib_plugin.so...(no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib20_zlib_plugin.so Reading symbols from /lib/libz.so.1...(no debugging symbols found)...done. Loaded symbols for /lib/libz.so.1 Reading symbols from /lib/libbz2.so.1...(no debugging symbols found)...done. Loaded symbols for /lib/libbz2.so.1 Reading symbols from /usr/lib/gcc/i686-pc-linux-gnu/4.3.4/libgcc_s.so.1...(no debugging symbols found)...done. Loaded symbols for /usr/lib/gcc/i686-pc-linux-gnu/4.3.4/libgcc_s.so.1
(no debugging symbols found) Core was generated by `imap'. Program terminated with signal 6, Aborted. [New process 29774] #0 0xffffe424 in __kernel_vsyscall () (gdb) bt full #0 0xffffe424 in __kernel_vsyscall () No symbol table info available. #1 0xb7e6e660 in raise () from /lib/libc.so.6 No symbol table info available. #2 0xb7e6fe98 in abort () from /lib/libc.so.6 No symbol table info available. #3 0xb7ea983d in ?? () from /lib/libc.so.6 No symbol table info available. #4 0x0000034f in ?? () No symbol table info available. #5 0xbfdb8624 in ?? () No symbol table info available. #6 0x00000400 in ?? () No symbol table info available. #7 0xb7f69da8 in ?? () from /lib/libc.so.6 No symbol table info available. #8 0x00000017 in ?? () No symbol table info available. #9 0xbfdb97fb in ?? () No symbol table info available. #10 0x00000004 in ?? () No symbol table info available. #11 0xb7f69dc1 in ?? () from /lib/libc.so.6 No symbol table info available. #12 0x00000002 in ?? () No symbol table info available. #13 0xb7f69ea0 in ?? () from /lib/libc.so.6 No symbol table info available. #14 0x00000021 in ?? () No symbol table info available. #15 0xb7f69dc5 in ?? () from /lib/libc.so.6 No symbol table info available. #16 0x00000004 in ?? () No symbol table info available. #17 0xbfdb8b53 in ?? () No symbol table info available. #18 0x00000008 in ?? () No symbol table info available. #19 0xb7f69dcb in ?? () from /lib/libc.so.6 No symbol table info available. #20 0x00000005 in ?? () No symbol table info available. #21 0x00000000 in ?? () No symbol table info available. (gdb) quit
Also all *.so libraries have "not stripped".
PS provided backtrace includes your patch.
On Thu, 2009-10-29 at 12:11 +0200, Nikita Koshikov wrote:
On Wed, 28 Oct 2009 14:17:52 -0400 Timo Sirainen <tss@iki.fi> wrote:
On Wed, 2009-10-28 at 10:39 +0200, Nikita Koshikov wrote:
Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Panic: data stack: Out of memory when allocating 268435472 bytes Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: *** glibc detected *** imap: double free or corruption (!prev): 0x0812ba00 ***
Oh, the double free is because of broken handling of out-of-memory error. http://hg.dovecot.org/dovecot-1.2/rev/acfef2f0fec3 probably fixes that.
Sorry, but this patch didn't help.
Not with the "out of memory", but did it get rid of the "double free or corruption" error?
Hmm. So I guess there's no memory corruption causing this, but I don't really see why it would try to allocate that much memory. 268435472 in hex is 0x10000010, which is an interesting number but doesn't really help much either. 268435456 is 256M which is max mail_process_size config setting, maybe this values is in use ?
I guess it's just exponentially increasing the buffer size then until it reaches mail_process_size.
I recompile dovecot binaries with debug symbols, but seemed that gdb backtrace is broken.
Yeah, it is. Hmm. Since the core isn't working, can you attach gdb to imap process while it's still running? So something like:
- open the account so imap process starts
- gdb -p <imap process pid>
- gdb command: c
- cause imap to crash -> gdb should stop
- gdb command: bt full
On Thu, 29 Oct 2009 12:38:22 -0400 Timo Sirainen <tss@iki.fi> wrote:
On Thu, 2009-10-29 at 12:11 +0200, Nikita Koshikov wrote:
On Wed, 28 Oct 2009 14:17:52 -0400 Timo Sirainen <tss@iki.fi> wrote:
On Wed, 2009-10-28 at 10:39 +0200, Nikita Koshikov wrote:
Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Panic: data stack: Out of memory when allocating 268435472 bytes Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: *** glibc detected *** imap: double free or corruption (!prev): 0x0812ba00 ***
Oh, the double free is because of broken handling of out-of-memory error. http://hg.dovecot.org/dovecot-1.2/rev/acfef2f0fec3 probably fixes that.
Sorry, but this patch didn't help.
Not with the "out of memory", but did it get rid of the "double free or corruption" error?
The valgrind error is the same. I'll attach current valgrid output. Also, I have noticed, that valgrind writes vgcore.* files in user's homedir, I attach gdb backtrace from that file.
Hmm. So I guess there's no memory corruption causing this, but I don't really see why it would try to allocate that much memory. 268435472 in hex is 0x10000010, which is an interesting number but doesn't really help much either. 268435456 is 256M which is max mail_process_size config setting, maybe this values is in use ?
I guess it's just exponentially increasing the buffer size then until it reaches mail_process_size.
I recompile dovecot binaries with debug symbols, but seemed that gdb backtrace is broken.
Yeah, it is. Hmm. Since the core isn't working, can you attach gdb to imap process while it's still running? So something like:
- open the account so imap process starts
- gdb -p <imap process pid>
- gdb command: c
- cause imap to crash -> gdb should stop
- gdb command: bt full
The problem, that webmail don't keep permanent connection, so when I login - there are about 2-3 imap-login\disconnected log entries. And when I try to get directory listing the new process created for this operation and then crushes. Can gdb work in non-interactive mode ? so I can write wrapper to handle debug output ?
Also I enable imap_debug feature on webmail client, as you say - it stop working after client trying to access "All" virtual folder. The appropriate imap-session log part is also attached.
Note, I can't reproduce panic with Thunderbird, this happens in roundcube only.
All virtual folder config is:
cat /var/mail/virtual/.all/dovecot-virtual #All messages in all folders * all
On Thu, 29 Oct 2009 12:38:22 -0400 Timo Sirainen <tss@iki.fi> wrote:
On Thu, 2009-10-29 at 12:11 +0200, Nikita Koshikov wrote:
On Wed, 28 Oct 2009 14:17:52 -0400 Timo Sirainen <tss@iki.fi> wrote:
On Wed, 2009-10-28 at 10:39 +0200, Nikita Koshikov wrote:
Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Panic: data stack: Out of memory when allocating 268435472 bytes Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: *** glibc detected *** imap: double free or corruption (!prev): 0x0812ba00 ***
Oh, the double free is because of broken handling of out-of-memory error. http://hg.dovecot.org/dovecot-1.2/rev/acfef2f0fec3 probably fixes that.
Sorry, but this patch didn't help.
Not with the "out of memory", but did it get rid of the "double free or corruption" error?
Hmm. So I guess there's no memory corruption causing this, but I don't really see why it would try to allocate that much memory. 268435472 in hex is 0x10000010, which is an interesting number but doesn't really help much either. 268435456 is 256M which is max mail_process_size config setting, maybe this values is in use ?
I guess it's just exponentially increasing the buffer size then until it reaches mail_process_size.
I recompile dovecot binaries with debug symbols, but seemed that gdb backtrace is broken.
Yeah, it is. Hmm. Since the core isn't working, can you attach gdb to imap process while it's still running? So something like:
- open the account so imap process starts
- gdb -p <imap process pid>
- gdb command: c
- cause imap to crash -> gdb should stop
- gdb command: bt full
One more note: version 1.2.4 also has this bug.
On Thu, 29 Oct 2009 12:38:22 -0400 Timo Sirainen <tss@iki.fi> wrote:
On Thu, 2009-10-29 at 12:11 +0200, Nikita Koshikov wrote:
On Wed, 28 Oct 2009 14:17:52 -0400 Timo Sirainen <tss@iki.fi> wrote:
On Wed, 2009-10-28 at 10:39 +0200, Nikita Koshikov wrote:
Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Panic: data stack: Out of memory when allocating 268435472 bytes Oct 26 15:26:38 IMAP(gozhda.a@domain.com): Error: *** glibc detected *** imap: double free or corruption (!prev): 0x0812ba00 ***
Oh, the double free is because of broken handling of out-of-memory error. http://hg.dovecot.org/dovecot-1.2/rev/acfef2f0fec3 probably fixes that.
Sorry, but this patch didn't help.
Not with the "out of memory", but did it get rid of the "double free or corruption" error?
Hmm. So I guess there's no memory corruption causing this, but I don't really see why it would try to allocate that much memory. 268435472 in hex is 0x10000010, which is an interesting number but doesn't really help much either. 268435456 is 256M which is max mail_process_size config setting, maybe this values is in use ?
I guess it's just exponentially increasing the buffer size then until it reaches mail_process_size.
I recompile dovecot binaries with debug symbols, but seemed that gdb backtrace is broken.
Yeah, it is. Hmm. Since the core isn't working, can you attach gdb to imap process while it's still running? So something like:
- open the account so imap process starts
- gdb -p <imap process pid>
- gdb command: c
- cause imap to crash -> gdb should stop
- gdb command: bt full
I found I way, to switch crash under telnet session and attach gdb to process, but this didn't produce valid trace:
GNU gdb 6.8 Copyright (C) 2008 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "i686-pc-linux-gnu". Attaching to process 29952 Reading symbols from /usr/libexec/dovecot/imap...(no debugging symbols found)...done. Reading symbols from /lib/libdl.so.2...(no debugging symbols found)...done. Loaded symbols for /lib/libdl.so.2 Reading symbols from /lib/librt.so.1...(no debugging symbols found)...done. Loaded symbols for /lib/librt.so.1 Reading symbols from /lib/libc.so.6...(no debugging symbols found)...done. Loaded symbols for /lib/libc.so.6 Reading symbols from /lib/ld-linux.so.2...(no debugging symbols found)...done. Loaded symbols for /lib/ld-linux.so.2 Reading symbols from /lib/libpthread.so.0... (no debugging symbols found)...done. [Thread debugging using libthread_db enabled] [New Thread 0xb7dccac0 (LWP 29952)] Loaded symbols for /lib/libpthread.so.0 Reading symbols from /usr/lib/dovecot/imap/lib10_quota_plugin.so...(no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib10_quota_plugin.so Reading symbols from /usr/lib/dovecot/imap/lib11_imap_quota_plugin.so...(no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib11_imap_quota_plugin.so Reading symbols from /usr/lib/dovecot/imap/lib11_trash_plugin.so...(no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib11_trash_plugin.so Reading symbols from /usr/lib/dovecot/imap/lib20_autocreate_plugin.so...(no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib20_autocreate_plugin.so Reading symbols from /usr/lib/dovecot/imap/lib20_expire_plugin.so... (no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib20_expire_plugin.so Reading symbols from /usr/lib/dovecot/imap/lib20_virtual_plugin.so...(no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib20_virtual_plugin.so Reading symbols from /usr/lib/dovecot/imap/lib20_zlib_plugin.so...(no debugging symbols found)...done. Loaded symbols for /usr/lib/dovecot/imap/lib20_zlib_plugin.so Reading symbols from /lib/libz.so.1...(no debugging symbols found)...done. Loaded symbols for /lib/libz.so.1 Reading symbols from /lib/libbz2.so.1...(no debugging symbols found)...done. Loaded symbols for /lib/libbz2.so.1
(no debugging symbols found) 0xffffe424 in __kernel_vsyscall () (gdb) cont Continuing. (no debugging symbols found)
Program received signal SIGABRT, Aborted. [Switching to Thread 0xb7dccac0 (LWP 29952)] 0xffffe424 in __kernel_vsyscall () (gdb) quit The program is running. Quit anyway (and detach it)? (y or n) yes Detaching from program: /usr/libexec/dovecot/imap, process 29952
I guess it's just exponentially increasing the buffer size then until it reaches mail_process_size.
I recompile dovecot binaries with debug symbols, but seemed that gdb backtrace is broken.
Yeah, it is. Hmm. Since the core isn't working, can you attach gdb to imap process while it's still running? So something like:
- open the account so imap process starts
- gdb -p <imap process pid>
- gdb command: c
- cause imap to crash -> gdb should stop
- gdb command: bt full
Today, I have updated to version 1.2.7 and I was able to get gdb-backtrace with it. This is clean installation without any patches applied.
Error-log: Nov 18 09:55:37 IMAP(alice@domain.com): Panic: data stack: Out of memory when allocating 268435472 bytes Nov 18 09:55:37 IMAP(alice@domain.com): Error: Raw backtrace: imap [0x80d2381] -> imap [0x80d23f2] -> imap [0x80d1d59] -> imap [0x80d0b2d] -> imap [0x80d0fa7] -> imap [0x80db928] -> imap [0x80cfeda] -> imap(buffer_write+0xd2) [0x80d03d2] -> imap(buffer_append+0x26) [0x80d04f6] -> imap(mail_transaction_log_append+0x61c) [0x80b54cc] -> imap [0x80aa029] -> imap(mail_index_sync_commit+0xa5) [0x80ad525] -> /usr/lib/dovecot/imap/lib20_virtual_plugin.so [0xb7ea8bc6] -> /usr/lib/dovecot/imap/lib20_virtual_plugin.so(virtual_storage_sync_init+0x71c) [0xb7eab6ac] -> imap(mailbox_sync+0x35) [0x8097595] -> imap(cmd_select_full+0x3d8) [0x8062fb8] -> imap(cmd_select+0x19) [0x80636f9] -> imap [0x806597c] -> imap [0x8065a23] -> imap(client_handle_input+0x2d) [0x8065b7d] -> imap(client_input+0x5f) [0x80664bf] -> imap(io_loop_handler_run+0xe0) [0x80da4e0] -> imap(io_loop_run+0x20) [0x80d9980] -> imap(main+0x5dc) [0x806ee4c] -> /lib/libc.so.6(__libc_start_main+0xe5) [0xb7ef6725] -> imap [0x805e281] Nov 18 09:55:37 dovecot: Error: child 9173 (imap) killed with signal 6 (core dumped)
Gdb-backtrace is attached.
On 11/18/2009, Nikita Koshikov (koshikov@gmail.com) wrote:
Today, I have updated to version 1.2.7 and I was able to get gdb-backtrace with it. This is clean installation without any patches applied.
Probably a good idea to always provide dovecot -n output too...
--
Best regards,
Charles
On Wed, 18 Nov 2009 06:18:06 -0500 Charles Marcus <CMarcus@Media-Brokers.com> wrote:
On 11/18/2009, Nikita Koshikov (koshikov@gmail.com) wrote:
Today, I have updated to version 1.2.7 and I was able to get gdb-backtrace with it. This is clean installation without any patches applied.
Probably a good idea to always provide dovecot -n output too...
It has been showed in my first post. Since that time config file didn't change.
On Wed, 2009-11-18 at 10:04 +0200, Nikita Koshikov wrote:
#10 0x080d03d2 in buffer_write (_buf=0xb7e1a670, pos=67100436, data=0xbb53ae0, data_size=32824) at buffer.c:63 No locals. #11 0x080d04f6 in buffer_append (buf=0xb7e1a670, data=0xbb53ae0, data_size=32824) at buffer.c:168 No locals. #12 0x080b54cc in mail_transaction_log_append (t=0xb205218, log_file_seq_r=0xbf8541f0, log_file_offset_r=0xbf8541e0) at mail-transaction-log-append.c:333
Interesting. If you still have the core and do:
fr 12 p *hdr p offset p hdrs[ext_id]
What does it print? Also could you try what it logs with the attached patch?
On Wed, 18 Nov 2009 11:55:40 -0500 Timo Sirainen <tss@iki.fi> wrote:
On Wed, 2009-11-18 at 10:04 +0200, Nikita Koshikov wrote:
#10 0x080d03d2 in buffer_write (_buf=0xb7e1a670, pos=67100436, data=0xbb53ae0, data_size=32824) at buffer.c:63 No locals. #11 0x080d04f6 in buffer_append (buf=0xb7e1a670, data=0xbb53ae0, data_size=32824) at buffer.c:168 No locals. #12 0x080b54cc in mail_transaction_log_append (t=0xb205218, log_file_seq_r=0xbf8541f0, log_file_offset_r=0xbf8541e0) at mail-transaction-log-append.c:333
Interesting. If you still have the core and do:
fr 12 p *hdr p offset p hdrs[ext_id]
With old core(not sure if it's exactly the same):
(gdb) fr 12 #12 0x080b54cc in mail_transaction_log_append (t=0xb205218, log_file_seq_r=0xbf8541f0, log_file_offset_r=0xbf8541e0) at mail-transaction-log-append.c:333 warning: Source file is more recent than executable. 333 } else { (gdb) p *hdr No symbol "hdr" in current context. (gdb) p offset No symbol "offset" in current context. (gdb) p hdrs[ext_id] No symbol "hdrs" in current context.
What does it print? Also could you try what it logs with the attached patch?
Here is logs, from new crash:
Nov 19 08:57:34 IMAP(alice@domain.com): Warning: header rewrite: size=32824 Nov 19 08:57:34 IMAP(alice@domain.com): Warning: mail_index_update_header_ext: ext_id=2 offset=0 size=32824 Nov 19 08:57:34 IMAP(alice@domain.com): Warning: log_append_ext_hdr_update: size=65536 Nov 19 08:57:35 IMAP(alice@domain.com): Panic: data stack: Out of memory when allocating 268435472 bytes Nov 19 08:57:35 IMAP(alice@agromat.ua): Error: Raw backtrace: imap [0x80d23e1] -> imap [0x80d2452] -> imap [0x80d1db9] -> imap [0x80d0b8d] -> imap [0x80d1007] -> imap [0x80db988] -> imap [0x80cff3a] -> imap(buffer_write+0xd2) [0x80d0432] -> imap(buffer_append+0x26) [0x80d0556] -> imap(mail_transaction_log_append+0x624) [0x80b5504] -> imap [0x80aa059] -> imap(mail_index_sync_commit+0xa5) [0x80ad555] -> /usr/lib/dovecot/imap/lib20_virtual_plugin.so [0xb7e6cc06] -> /usr/lib/dovecot/imap/lib20_virtual_plugin.so(virtual_storage_sync_init+0x71c) [0xb7e6f71c] -> imap(mailbox_sync+0x35) [0x8097595] -> imap(cmd_select_full+0x3d8) [0x8062fb8] -> imap(cmd_select+0x19) [0x80636f9] -> imap [0x806597c] -> imap [0x8065a23] -> imap(client_handle_input+0x2d) [0x8065b7d] -> imap(client_input+0x5f) [0x80664bf] -> imap(io_loop_handler_run+0xe0) [0x80da540] -> imap(io_loop_run+0x20) [0x80d99e0] -> imap(main+0x5dc) [0x806ee4c] -> /lib/libc.so.6(__libc_start_main+0xe5) [0xb7eba725] -> imap [0x805e281] Nov 19 08:57:36 dovecot: Error: child 16124 (imap) killed with signal 6 (core dumped)
From new core file: (gdb) fr 12 #12 0x080b5504 in mail_transaction_log_append (t=0xb205218, log_file_seq_r=0xbf9162b0, log_file_offset_r=0xbf9162a0) at mail-transaction-log-append.c:337 337 mail-transaction-log-append.c: No such file or directory. in mail-transaction-log-append.c (gdb) p *hdr No symbol "hdr" in current context. (gdb) p offset No symbol "offset" in current context. (gdb) p hdrs[ext_id] No symbol "hdrs" in current context.
And attached current gdb-trace.
On Thu, 2009-11-19 at 09:10 +0200, Nikita Koshikov wrote:
Nov 19 08:57:34 IMAP(alice@domain.com): Warning: header rewrite: size=32824 Nov 19 08:57:34 IMAP(alice@domain.com): Warning: mail_index_update_header_ext: ext_id=2 offset=0 size=32824 Nov 19 08:57:34 IMAP(alice@domain.com): Warning: log_append_ext_hdr_update: size=65536
Thanks. Pretty simple fix after all that I missed: http://hg.dovecot.org/dovecot-1.2/rev/3e1ca490dde0
On Thu, 2009-11-19 at 18:31 -0500, Timo Sirainen wrote:
On Thu, 2009-11-19 at 09:10 +0200, Nikita Koshikov wrote:
Nov 19 08:57:34 IMAP(alice@domain.com): Warning: header rewrite: size=32824 Nov 19 08:57:34 IMAP(alice@domain.com): Warning: mail_index_update_header_ext: ext_id=2 offset=0 size=32824 Nov 19 08:57:34 IMAP(alice@domain.com): Warning: log_append_ext_hdr_update: size=65536
Thanks. Pretty simple fix after all that I missed: http://hg.dovecot.org/dovecot-1.2/rev/3e1ca490dde0
Except .. although that above patch helps a bit, it still breaks after header size goes to 64k and fixing that requires changing index file format a bit. This should help there: http://hg.dovecot.org/dovecot-1.2/rev/e5d38150be58
On Thu, 19 Nov 2009 18:53:19 -0500 Timo Sirainen <tss@iki.fi> wrote:
On Thu, 2009-11-19 at 18:31 -0500, Timo Sirainen wrote:
On Thu, 2009-11-19 at 09:10 +0200, Nikita Koshikov wrote:
Nov 19 08:57:34 IMAP(alice@domain.com): Warning: header rewrite: size=32824 Nov 19 08:57:34 IMAP(alice@domain.com): Warning: mail_index_update_header_ext: ext_id=2 offset=0 size=32824 Nov 19 08:57:34 IMAP(alice@domain.com): Warning: log_append_ext_hdr_update: size=65536
Thanks. Pretty simple fix after all that I missed: http://hg.dovecot.org/dovecot-1.2/rev/3e1ca490dde0
Except .. although that above patch helps a bit, it still breaks after header size goes to 64k and fixing that requires changing index file format a bit. This should help there: http://hg.dovecot.org/dovecot-1.2/rev/e5d38150be58
Sorry, but with version 1.2.8 the crash is still here:
Nov 20 10:16:00 IMAP(alice@domain.com): Panic: file mail-transaction-log-append.c: line 31 (log_append_buffer): assertion failed: ((type & MAIL_TRANSACTION_) Nov 20 10:16:00 IMAP(alice@domain.com): Error: Raw backtrace: imap [0x80d2411] -> imap [0x80d2482] -> imap [0x80d1de9] -> imap [0x80b4a9f] -> imap(mail_tran] Nov 20 10:16:00 dovecot: Error: child 29596 (imap) killed with signal 6 (core dumped)
I have tried delete old indexes, but this didn't help.
current gdb-trace is attached.
On Fri, 2009-11-20 at 10:23 +0200, Nikita Koshikov wrote:
Nov 20 10:16:00 IMAP(alice@domain.com): Panic: file mail-transaction-log-append.c: line 31 (log_append_buffer): assertion failed: ((type & MAIL_TRANSACTION_)
Oh, missed that one: http://hg.dovecot.org/dovecot-1.2/rev/fa8a438c64ce
On Fri, 20 Nov 2009 13:53:18 -0500 Timo Sirainen <tss@iki.fi> wrote:
On Fri, 2009-11-20 at 10:23 +0200, Nikita Koshikov wrote:
Nov 20 10:16:00 IMAP(alice@domain.com): Panic: file mail-transaction-log-append.c: line 31 (log_append_buffer): assertion failed: ((type & MAIL_TRANSACTION_)
Oh, missed that one: http://hg.dovecot.org/dovecot-1.2/rev/fa8a438c64ce
With above patch applied, I got this one crash:
Nov 23 09:42:59 IMAP(alice@domain.com): Panic: file mail-index-sync-ext.c: line 625 (mail_index_sync_ext_hdr_update): assertion failed: (ext->hdr_offset + offset + size <= map->hdr.header_size) Nov 23 09:42:59 IMAP(alice@domain.com): Error: Raw backtrace: imap [0x80d2521] -> imap [0x80d2592] -> imap [0x80d1ef9] -> imap [0x80c06ef] -> imap(mail_index_sync_record+0x210) [0x80af010] -> imap(mail_index_sync_map+0x2b9) [0x80afd39] -> imap(mail_index_map+0x3c4) [0x80a4f34] -> imap(mail_index_sync_commit+0xc2) [0x80ad552] -> /usr/lib/dovecot/imap/lib20_virtual_plugin.so [0xb7deebc6] -> /usr/lib/dovecot/imap/lib20_virtual_plugin.so(virtual_storage_sync_init+0x71c) [0xb7df16ac] -> imap(mailbox_sync+0x35) [0x80975a5] -> imap(cmd_select_full+0x3d8) [0x8062fe8] -> imap(cmd_select+0x19) [0x8063729] -> imap [0x80659ac] -> imap [0x8065a53] -> imap(client_handle_input+0x2d) [0x8065bad] -> imap(client_input+0x5f) [0x80664ef] -> imap(io_loop_handler_run+0xe0) [0x80da680] -> imap(io_loop_run+0x20) [0x80d9b20] -> imap(main+0x5dc) [0x806ee7c] -> /lib/libc.so.6(__libc_start_main+0xe5) [0xb7e3c725] -> imap [0x805e2b1] Nov 23 09:43:00 dovecot: Error: child 19671 (imap) killed with signal 6 (core dumped)
Gdb trace in attachment.
On Mon, 2009-11-23 at 09:59 +0200, Nikita Koshikov wrote:
With above patch applied, I got this one crash:
Nov 23 09:42:59 IMAP(alice@domain.com): Panic: file mail-index-sync-ext.c: line 625 (mail_index_sync_ext_hdr_update): assertion failed: (ext->hdr_offset + offset + size <= map->hdr.header_size)
Fixed: http://hg.dovecot.org/dovecot-1.2/rev/40a6a70b3146
Also that crash doesn't get fixed by itself, so either delete the virtual mailbox's dovecot.index* files or/and apply this patch:
http://hg.dovecot.org/dovecot-1.2/rev/9a8eb4d68b04
And I finally created 1000 mailboxes myself and tested that it actually works now.
On Mon, 23 Nov 2009 11:46:35 -0500 Timo Sirainen <tss@iki.fi> wrote:
On Mon, 2009-11-23 at 09:59 +0200, Nikita Koshikov wrote:
With above patch applied, I got this one crash:
Nov 23 09:42:59 IMAP(alice@domain.com): Panic: file mail-index-sync-ext.c: line 625 (mail_index_sync_ext_hdr_update): assertion failed: (ext->hdr_offset + offset + size <= map->hdr.header_size)
Finally it works!!! Thanks.
Also that crash doesn't get fixed by itself, so either delete the virtual mailbox's dovecot.index* files or/and apply this patch:
My indexes are located in the memory (:INDEX=MEMORY:) so I don't apply this patch. If you need me to test it - please let me know.
And I finally created 1000 mailboxes myself and tested that it actually works now.
Again, Thanks for your work.
participants (3)
-
Charles Marcus
-
Nikita Koshikov
-
Timo Sirainen