[Dovecot] [dovecot-2.1.15] mdbox corruption, doveadm force-resync can't repair it (throws segfault)
Hi Timo, hi all! Today i noticed imap throws segmentation faults and dumps cores. I looked into logs I can see: 2013-03-07T12:12:52.257986+01:00 meteor dovecot: imap(marcinxxx@kolekcja.mejor.pl) <7sRXtFPXYAA+eX93>: Error: Corrupted dbox file /dane/domeny/mejor.pl/mail/marcin//.mdbox/mailinglists/storage/m.75 (around offset=2779212): EOF reading msg header (got 0/30 bytes) 2013-03-07T12:12:52.258052+01:00 meteor dovecot: imap(marcinxxx@kolekcja.mejor.pl) <7sRXtFPXYAA+eX93>: Disconnected: Internal error occurred. Refer to server log for more information. [2013-03-07 12:12:52] in=5940 out=6637723 2013-03-07T12:12:52.258595+01:00 meteor dovecot: imap(marcinxxx@kolekcja.mejor.pl) <7sRXtFPXYAA+eX93>: Warning: fscking index file /dane/domeny/mejor.pl/mail/marcin//.mdbox/mailinglists/storage/dovecot.map.index 2013-03-07T12:12:52.285176+01:00 meteor dovecot: imap(marcinxxx@kolekcja.mejor.pl) <7sRXtFPXYAA+eX93>: Warning: mdbox /dane/domeny/mejor.pl/mail/marcin//.mdbox/mailinglists/storage: rebuilding indexes 2013-03-07T12:12:55.618752+01:00 meteor dovecot: imap(marcinxxx@kolekcja.mejor.pl) <7sRXtFPXYAA+eX93>: Fatal: master: service(imap): child 25626 killed with signal 11 (core dumped)
Here is backtrace: echo -e "bt\nbt full" |gdb -q /usr/libexec/dovecot/imap 'core-1362654775-8-11-!usr!libexec!dovecot!imap-25626'
[Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/libthread_db.so.1".
warning: no loadable sections found in added symbol-file system-supplied
DSO at 0x2c831788000
Core was generated by `dovecot/imap'.
Program terminated with signal 11, Segmentation fault.
#0 rebuild_mailbox_multi (trans=0x751c14c870, view=<optimized out>,
rebuild_ctx=0x751c14cbf0, ctx=0x751c007c00, mbox=<optimized out>) at
mdbox-storage-rebuild.c:433
433 mdbox-storage-rebuild.c: Nie ma takiego pliku ani katalogu.
(gdb) #0 rebuild_mailbox_multi (trans=0x751c14c870, view=<optimized
out>, rebuild_ctx=0x751c14cbf0, ctx=0x751c007c00, mbox=<optimized out>)
at mdbox-storage-rebuild.c:433
#1 rebuild_mailbox (vname=<optimized out>, ctx=0x751c007c00,
ns=<optimized out>) at mdbox-storage-rebuild.c:546
#2 rebuild_namespace_mailboxes (ns=<optimized out>, ctx=0x751c007c00)
at mdbox-storage-rebuild.c:577
#3 rebuild_mailboxes (ctx=0x751c007c00) at mdbox-storage-rebuild.c:597
#4 mdbox_storage_rebuild_scan (ctx=0x751c007c00) at
mdbox-storage-rebuild.c:905
#5 mdbox_storage_rebuild_in_context (storage=0x751bf477a0,
atomic=<optimized out>) at mdbox-storage-rebuild.c:928
#6 0x000002c8316c7703 in mdbox_storage_rebuild (storage=0x751bf477a0)
at mdbox-storage-rebuild.c:944
#7 0x000002c8316c4d85 in mdbox_mailbox_close (box=0x751c0134b0) at
mdbox-storage.c:195
#8 0x000002c8316f195e in mailbox_close (box=0x751c0134b0) at
mail-storage.c:984
#9 0x000002c8316f19e7 in mailbox_free (_box=<optimized out>) at
mail-storage.c:997
#10 0x000000751aabc869 in client_destroy (client=0x751bf6e220,
reason=<optimized out>) at imap-client.c:213
#11 0x000000751aabcc7a in client_input (client=0x751bf6e220) at
imap-client.c:843
#12 0x000002c83163a4b6 in io_loop_call_io (io=0x751bf939c0) at ioloop.c:379
#13 0x000002c83163b647 in io_loop_handler_run (ioloop=<optimized out>)
at ioloop-epoll.c:213
#14 0x000002c831639eb0 in io_loop_run (ioloop=0x751bf26350) at ioloop.c:398
#15 0x000002c831620827 in master_service_run (service=0x751bf26200,
callback=<optimized out>) at master-service.c:544
#16 0x000000751aac65e5 in main (argc=1, argv=0x751bf26040) at main.c:389
(gdb) #0 rebuild_mailbox_multi (trans=0x751c14c870, view=<optimized
out>, rebuild_ctx=0x751c14cbf0, ctx=0x751c007c00, mbox=<optimized out>)
at mdbox-storage-rebuild.c:433
new_seq = 17683
hdr = 0x751c004ae0
data = 0x751c08348c
expunged = false
uid = 8877
map_uid = 127994
new_dbox_rec = {map_uid = 127994, save_date = 1362612657}
rec = 0x0
old_seq = <optimized out>
#1 rebuild_mailbox (vname=<optimized out>, ctx=0x751c007c00,
ns=<optimized out>) at mdbox-storage-rebuild.c:546
box = 0x751bf7af30
mbox = 0x751bf7af30
rebuild_ctx = 0x751c14cbf0
ret = <optimized out>
sync_ctx = 0x751c0132b0
view = 0x751c004f20
trans = 0x751c14c870
error = <optimized out>
#2 rebuild_namespace_mailboxes (ns=<optimized out>, ctx=0x751c007c00)
at mdbox-storage-rebuild.c:577
_data_stack_cur_id = 3
iter = 0x751c000340
info = <optimized out>
ret = 0
#3 rebuild_mailboxes (ctx=0x751c007c00) at mdbox-storage-rebuild.c:597
storage = <optimized out>
ns = <optimized out>
#4 mdbox_storage_rebuild_scan (ctx=0x751c007c00) at
mdbox-storage-rebuild.c:905
data = 0x751c00c2c0
data_size = 8
#5 mdbox_storage_rebuild_in_context (storage=0x751bf477a0,
atomic=<optimized out>) at mdbox-storage-rebuild.c:928
ctx = 0x5137d1b10001f3fa
ret = 0
#6 0x000002c8316c7703 in mdbox_storage_rebuild (storage=0x751bf477a0)
at mdbox-storage-rebuild.c:944
atomic = 0x751bf983f0
ret = <optimized out>
#7 0x000002c8316c4d85 in mdbox_mailbox_close (box=0x751c0134b0) at
mdbox-storage.c:195
mstorage = <optimized out>
#8 0x000002c8316f195e in mailbox_close (box=0x751c0134b0) at
mail-storage.c:984
No locals.
#9 0x000002c8316f19e7 in mailbox_free (_box=<optimized out>) at
mail-storage.c:997
box = 0x751c0134b0
#10 0x000000751aabc869 in client_destroy (client=0x751bf6e220,
reason=<optimized out>) at imap-client.c:213
cmd = <optimized out>
__FUNCTION__ = "client_destroy"
#11 0x000000751aabcc7a in client_input (client=0x751bf6e220) at
imap-client.c:843
cmd = 0x2c83163a1fe
doveadm -v force-resync -u marcinxxx@kolekcja.mejor.pl "mailinglists.*" doveadm(marcinxxx@kolekcja.mejor.pl): Warning: fscking index file /dane/domeny/mejor.pl/mail/marcin//.mdbox/mailinglists/storage/dovecot.map.index doveadm(marcinxxx@kolekcja.mejor.pl): Warning: mdbox /dane/domeny/mejor.pl/mail/marcin//.mdbox/mailinglists/storage: rebuilding indexes Segmentation fault
How should I repair mdbox file?
I have another question, doveadm force-resync -A "*"
doesn't do resync
inside namespace. Is it feature or bug?;)
Thanks, Marcin
# 2.1.15: /etc/dovecot/dovecot.conf # OS: Linux 3.7.5-hardened-r1 x86_64 Gentoo Base System release 2.1 auth_cache_size = 1 k auth_mechanisms = login digest-md5 cram-md5 plain deliver_log_format = msgid=%m: from=%f: phys=%p: virt=%w %$ dict { quota = pgsql:/etc/dovecot/dovecot-dict-sql.conf.ext } first_valid_uid = 8 last_valid_uid = 8 lda_mailbox_autocreate = yes lda_mailbox_autosubscribe = yes mail_attachment_dir = /dane/domeny/zalaczniki mail_attachment_min_size = 10000 k mail_cache_min_mail_count = 20 mail_gid = mail mail_log_prefix = "%s(%u) <%{session}>: " mail_plugins = autocreate quota notify mail_log stats zlib mail_privileged_group = mail mail_uid = mail maildir_stat_dirs = yes 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 mdbox_preallocate_space = yes mdbox_rotate_interval = 60 days mdbox_rotate_size = 50 M namespace inbox { inbox = yes list = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } # 2.1.15: /etc/dovecot/dovecot.conf # OS: Linux 3.7.5-hardened-r1 x86_64 Gentoo Base System release 2.1 auth_cache_size = 1 k auth_mechanisms = login digest-md5 cram-md5 plain deliver_log_format = msgid=%m: from=%f: phys=%p: virt=%w %$ dict { quota = pgsql:/etc/dovecot/dovecot-dict-sql.conf.ext } first_valid_uid = 8 last_valid_uid = 8 lda_mailbox_autocreate = yes lda_mailbox_autosubscribe = yes mail_attachment_dir = /dane/domeny/zalaczniki mail_attachment_min_size = 10000 k mail_cache_min_mail_count = 20 mail_gid = mail mail_log_prefix = "%s(%u) <%{session}>: " mail_plugins = autocreate quota notify mail_log stats zlib mail_privileged_group = mail mail_uid = mail maildir_stat_dirs = yes 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 mdbox_preallocate_space = yes mdbox_rotate_interval = 60 days mdbox_rotate_size = 50 M namespace inbox { inbox = yes list = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } postmaster_address = postmaster@mejor.pl protocols = imap pop3 sieve service auth { unix_listener auth-userdb { group = mail mode = 0660 user = root } } service dict { unix_listener dict { user = mail } } service stats { fifo_listener stats-mail { mode = 0600 user = mail } } ssl_cert =
Here is backtrace from doveadm force-resync:
gdb -q /usr/bin/doveadm 'core-1362658246-8-11-!usr!bin!doveadm-3939' Reading symbols from /usr/bin/doveadm...Reading symbols from /usr/lib64/debug/usr/bin/doveadm.debug...done. done. [New LWP 3939]
warning: Could not load shared library symbols for linux-vdso.so.1. Do you need "set solib-search-path" or "set sysroot"? [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/libthread_db.so.1".
warning: no loadable sections found in added symbol-file system-supplied DSO at 0x3667f202000 Core was generated by `doveadm -v force-resync -u marcin@mejor.pl mailinglists.*'. Program terminated with signal 11, Segmentation fault. #0 rebuild_mailbox_multi (trans=0x428b58d090, view=<optimized out>, rebuild_ctx=0x428b5a0690, ctx=0x428b57a9a0, mbox=<optimized out>) at mdbox-storage-rebuild.c:433 433 map_uid = rec->map_uid; (gdb) bt #0 rebuild_mailbox_multi (trans=0x428b58d090, view=<optimized out>, rebuild_ctx=0x428b5a0690, ctx=0x428b57a9a0, mbox=<optimized out>) at mdbox-storage-rebuild.c:433 #1 rebuild_mailbox (vname=<optimized out>, ctx=0x428b57a9a0, ns=<optimized out>) at mdbox-storage-rebuild.c:546 #2 rebuild_namespace_mailboxes (ns=<optimized out>, ctx=0x428b57a9a0) at mdbox-storage-rebuild.c:577 #3 rebuild_mailboxes (ctx=0x428b57a9a0) at mdbox-storage-rebuild.c:597 #4 mdbox_storage_rebuild_scan (ctx=0x428b57a9a0) at mdbox-storage-rebuild.c:905 #5 mdbox_storage_rebuild_in_context (storage=0x428b52e290, atomic=<optimized out>) at mdbox-storage-rebuild.c:928 #6 0x000003667f13356a in mdbox_sync_begin (mbox=0x428b564a90, flags=MDBOX_SYNC_FLAG_FORCE_REBUILD, atomic=0x428b57ef10, ctx_r=0x3bcda49d568) at mdbox-sync.c:235 #7 0x000003667f133b75 in mdbox_sync (mbox=0x428b564a90, flags=MDBOX_SYNC_FLAG_FORCE_REBUILD) at mdbox-sync.c:319 #8 0x000003667f133c86 in mdbox_storage_sync_init (box=0x428b564a90, flags=(MAILBOX_SYNC_FLAG_FIX_INCONSISTENT | MAILBOX_SYNC_FLAG_FORCE_RESYNC)) at mdbox-sync.c:349 #9 0x000003667f161631 in mailbox_sync_init (box=0x428b564a90, flags=(MAILBOX_SYNC_FLAG_FIX_INCONSISTENT | MAILBOX_SYNC_FLAG_FORCE_RESYNC)) at mail-storage.c:1326 #10 0x000003667f1617b7 in mailbox_sync (box=<optimized out>, flags=<optimized out>) at mail-storage.c:1374 #11 0x0000004289345a33 in cmd_force_resync_box (ctx=0x428b511de0, info=<optimized out>) at doveadm-mail.c:211 #12 cmd_force_resync_run (ctx=0x428b511de0, user=<optimized out>) at doveadm-mail.c:240 #13 0x000000428934566d in doveadm_mail_next_user (error_r=0x3bcda49d6c0, ctx=0x428b511de0, input=<optimized out>) at doveadm-mail.c:311 #14 doveadm_mail_next_user (ctx=0x428b511de0, input=<optimized out>, error_r=0x3bcda49d6c0) at doveadm-mail.c:270 #15 0x000000428934646e in doveadm_mail_cmd (cmd=0x428b511480, argc=4, argv=0x428b50d578) at doveadm-mail.c:520 #16 0x0000004289346a01 in doveadm_mail_try_run (cmd_name=0x428b50d593 "force-resync", argc=4, argv=0x428b50d560) at doveadm-mail.c:579 #17 0x000000428934f4eb in main (argc=4, argv=0x428b50d560) at doveadm.c:391
bt full:
#0 rebuild_mailbox_multi (trans=0x428b58d090, view=<optimized out>,
rebuild_ctx=0x428b5a0690, ctx=0x428b57a9a0, mbox=<optimized out>) at
mdbox-storage-rebuild.c:433
433 map_uid = rec->map_uid;
(gdb) #0 rebuild_mailbox_multi (trans=0x428b58d090, view=<optimized
out>, rebuild_ctx=0x428b5a0690, ctx=0x428b57a9a0, mbox=<optimized out>)
at mdbox-storage-rebuild.c:433
new_seq = 17684
hdr = 0x428b59fae0
data = 0x428b61ea8c
expunged = false
uid = 8877
map_uid = 127994
new_dbox_rec = {map_uid = 127994, save_date = 1362612657}
rec = 0x0
old_seq = <optimized out>
#1 rebuild_mailbox (vname=<optimized out>, ctx=0x428b57a9a0,
ns=<optimized out>) at mdbox-storage-rebuild.c:546
box = 0x428b5ae880
mbox = 0x428b5ae880
rebuild_ctx = 0x428b5a0690
ret = <optimized out>
sync_ctx = 0x428b5a10e0
view = 0x428b5a1ae0
trans = 0x428b58d090
error = <optimized out>
#2 rebuild_namespace_mailboxes (ns=<optimized out>, ctx=0x428b57a9a0)
at mdbox-storage-rebuild.c:577
_data_stack_cur_id = 4
iter = 0x428b585620
info = <optimized out>
ret = 0
#3 rebuild_mailboxes (ctx=0x428b57a9a0) at mdbox-storage-rebuild.c:597
storage = <optimized out>
ns = <optimized out>
#4 mdbox_storage_rebuild_scan (ctx=0x428b57a9a0) at
mdbox-storage-rebuild.c:905
data = 0x428b589e10
data_size = 8
#5 mdbox_storage_rebuild_in_context (storage=0x428b52e290,
atomic=<optimized out>) at mdbox-storage-rebuild.c:928
ctx = 0x5137d1b10001f3fa
ret = 0
#6 0x000003667f13356a in mdbox_sync_begin (mbox=0x428b564a90,
flags=MDBOX_SYNC_FLAG_FORCE_REBUILD, atomic=0x428b57ef10,
ctx_r=0x3bcda49d568) at mdbox-sync.c:235
storage = 0x428b52e290
ctx = <optimized out>
sync_flags = <optimized out>
ret = 4
rebuild = true
storage_rebuilt = false
#7 0x000003667f133b75 in mdbox_sync (mbox=0x428b564a90,
flags=MDBOX_SYNC_FLAG_FORCE_REBUILD) at mdbox-sync.c:319
sync_ctx = 0x0
atomic = 0x428b57ef10
ret = <optimized out>
#8 0x000003667f133c86 in mdbox_storage_sync_init (box=0x428b564a90,
flags=(MAILBOX_SYNC_FLAG_FIX_INCONSISTENT |
MAILBOX_SYNC_FLAG_FORCE_RESYNC)) at mdbox-sync.c:349
mbox = 0x428b564a90
mdbox_sync_flags = <optimized out>
ret = <optimized out>
#9 0x000003667f161631 in mailbox_sync_init (box=0x428b564a90,
flags=(MAILBOX_SYNC_FLAG_FIX_INCONSISTENT |
MAILBOX_SYNC_FLAG_FORCE_RESYNC)) at mail-storage.c:1326
_data_stack_cur_id = 3
ctx = <optimized out>
#10 0x000003667f1617b7 in mailbox_sync (box=<optimized out>,
flags=<optimized out>) at mail-storage.c:1374
ctx = <optimized out>
status = {sync_delayed_expunges = 0}
#11 0x0000004289345a33 in cmd_force_resync_box (ctx=0x428b511de0,
info=<optimized out>) at doveadm-mail.c:211
box = 0x428b564a90
ret = 0
#12 cmd_force_resync_run (ctx=0x428b511de0, user=<optimized out>) at
doveadm-mail.c:240
_data_stack_cur_id = 2
iter = 0x428b554d40
info = 0x428b556e70
ret = 0
#13 0x000000428934566d in doveadm_mail_next_user (error_r=0x3bcda49d6c0,
ctx=0x428b511de0, input=<optimized out>) at doveadm-mail.c:311
ret = 0
#14 doveadm_mail_next_user (ctx=0x428b511de0, input=<optimized out>,
error_r=0x3bcda49d6c0) at doveadm-mail.c:270
error = <optimized out>
ret = <optimized out>
#15 0x000000428934646e in doveadm_mail_cmd (cmd=0x428b511480, argc=4,
argv=0x428b50d578) at doveadm-mail.c:520
input = {module = 0x0, service = 0x4289370302 "doveadm",
username = 0x428b50d5a3 "marcin@mejor.pl", session_id = 0x0, local_ip =
{family = 0, u = {ip6 = {
__in6_u = {__u6_addr8 = '\000'
clang static analyzer also suspect dereference of null pointer in mdbox-storage-rebuild.c 433 (if you can't have fresh analyse here it is: http://mejor.pl/clang-analysis/dovecot-2.15/ )
On 7.3.2013, at 14.12, Marcin Mirosław marcin@mejor.pl wrote:
Here is backtrace from doveadm force-resync:
#0 rebuild_mailbox_multi (trans=0x428b58d090, view=<optimized out>, rebuild_ctx=0x428b5a0690, ctx=0x428b57a9a0, mbox=<optimized out>) at mdbox-storage-rebuild.c:433 433 map_uid = rec->map_uid;
Yeah, I fixed this immediately after 2.1.15: http://hg.dovecot.org/dovecot-2.1/rev/2def25f07ca6
I guess it's soon time for 2.1.16.
W dniu 20.03.2013 18:20, Timo Sirainen pisze:
On 7.3.2013, at 14.12, Marcin Mirosław marcin@mejor.pl wrote:
Here is backtrace from doveadm force-resync:
#0 rebuild_mailbox_multi (trans=0x428b58d090, view=<optimized out>, rebuild_ctx=0x428b5a0690, ctx=0x428b57a9a0, mbox=<optimized out>) at mdbox-storage-rebuild.c:433 433 map_uid = rec->map_uid;
Yeah, I fixed this immediately after 2.1.15: http://hg.dovecot.org/dovecot-2.1/rev/2def25f07ca6
I guess it's soon time for 2.1.16.
Hi! I've aplied patch and force-resync finished work without problem.Thanks!
I asked one more question: doveadm force-resync -A "*"
doesn't do
resync inside namespace. Is it feature or bug?
Thanks.
Marcin
On Thu, 2013-03-21 at 10:41 +0100, Marcin Mirosław wrote:
W dniu 20.03.2013 18:20, Timo Sirainen pisze:
On 7.3.2013, at 14.12, Marcin Mirosław marcin@mejor.pl wrote:
Here is backtrace from doveadm force-resync:
#0 rebuild_mailbox_multi (trans=0x428b58d090, view=<optimized out>, rebuild_ctx=0x428b5a0690, ctx=0x428b57a9a0, mbox=<optimized out>) at mdbox-storage-rebuild.c:433 433 map_uid = rec->map_uid;
Yeah, I fixed this immediately after 2.1.15: http://hg.dovecot.org/dovecot-2.1/rev/2def25f07ca6
I guess it's soon time for 2.1.16.
Hi! I've aplied patch and force-resync finished work without problem.Thanks! I asked one more question:
doveadm force-resync -A "*"
doesn't do resync inside namespace. Is it feature or bug?
What exactly do you mean? I think it should only resync the mailboxes in the prefix="" namespace, or at least that's the intended behavior with other commands where "*" is used. Is -A relevant here (= does it happen the same with -u username)?
participants (2)
-
Marcin Mirosław
-
Timo Sirainen