Marcin Mirosław
2013-Mar-07 11:46 UTC
[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 at 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 at 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 at 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 at 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 at 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 <io_loop_context_activate+78> output = 0x0 bytes = 208 __FUNCTION__ = "client_input" #12 0x000002c83163a4b6 in io_loop_call_io (io=0x751bf939c0) at ioloop.c:379 ioloop = 0x751bf26350 t_id = 2 #13 0x000002c83163b647 in io_loop_handler_run (ioloop=<optimized out>) at ioloop-epoll.c:213 ctx = 0x751bf266c0 events = 0x0 event = 0x751bf26730 list = 0x751bf6fff0 io = <optimized out> tv = {tv_sec = 4, tv_usec = 921146} msecs = <optimized out> ret = 1 i = <optimized out> call = <optimized out> #14 0x000002c831639eb0 in io_loop_run (ioloop=0x751bf26350) at ioloop.c:398 No locals. #15 0x000002c831620827 in master_service_run (service=0x751bf26200, callback=<optimized out>) at master-service.c:544 No locals. #16 0x000000751aac65e5 in main (argc=1, argv=0x751bf26040) at main.c:389 set_roots = {0x751aacdfa0 <imap_setting_parser_info>, 0x0} login_set = {auth_socket_path = 0x751bf1dd40 "/run/dovecot/auth-master", postlogin_socket_path = 0x0, postlogin_timeout_secs = 60, callback = 0x751aac5e80 <login_client_connected>, failure_callback = 0x751aac5b90 <login_client_failed>} service_flags = <optimized out> storage_service_flags = <optimized out> username = <optimized out> c = <optimized out> (gdb) quit doveadm -v force-resync -u marcinxxx at kolekcja.mejor.pl "mailinglists.*" doveadm(marcinxxx at kolekcja.mejor.pl): Warning: fscking index file /dane/domeny/mejor.pl/mail/marcin//.mdbox/mailinglists/storage/dovecot.map.index doveadm(marcinxxx at 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 at 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 = </etc/ssl/gwiazdka.mejor.pl.pem ssl_key = </etc/ssl/gwiazdka.mejor.pl.pem userdb { driver = prefetch } userdb { args = /etc/dovecot/dovecot-sql.conf.ext driver = sql } verbose_proctitle = yes protocol lda { mail_plugins = autocreate quota notify mail_log stats zlib sieve } protocol imap { mail_max_userip_connections = 25 mail_plugins = autocreate quota notify mail_log stats zlib imap_quota imap_stats imap_zlib }
Marcin Mirosław
2013-Mar-07 12:12 UTC
[Dovecot] [dovecot-2.1.15] mdbox corruption, doveadm force-resync can't repair it (throws segfault)
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 at 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 at mejor.pl", session_id = 0x0, local_ip {family = 0, u = {ip6 = { __in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, ip4 = {s_addr = 0}}}, remote_ip = {family = 0, u = {ip6 = {__in6_u = {__u6_addr8 '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, ip4 = {s_addr = 0}}}, local_port = 0, remote_port = 0, userdb_fields = 0x0, flags_override_add = (unknown: 0), flags_override_remove = (unknown: 0), no_userdb_lookup = 0} ctx = 0x428b511de0 getopt_args = 0x42893702e5 "AS:u:" wildcard_user = 0x0 error = <optimized out> ret = <optimized out> c = <optimized out> #16 0x0000004289346a01 in doveadm_mail_try_run (cmd_name=0x428b50d593 "force-resync", argc=4, argv=0x428b50d560) at doveadm-mail.c:579 cmd__foreach_end = 0x428b511690 cmd = 0x428b511480 cmd_name_len = <optimized out> __FUNCTION__ = "doveadm_mail_try_run" #17 0x000000428934f4eb in main (argc=4, argv=0x428b50d560) at doveadm.c:391 cmd_name = <optimized out> i = <optimized out> quick_init = false c = <optimized out> (gdb) quit