Panic on cleanup

Aki Tuomi
2016-08-31T06:56:20Z

On 12.07.2016 22:25, Harald Leithner wrote:
> Hi,
>
> I got a doveadm panic while running purge -A with 2.2.25
>
>
> doveadm(x at itronic.at): Panic: file mdbox-map.c: line 1359: unreached
> doveadm(x at itronic.at): Error: Raw backtrace:
> /usr/lib/dovecot/libdovecot.so.0(+0x8dc6e) [0x7f2fe2022c6e] ->
> /usr/lib/dovecot/libdovecot.so.0(+0x8dce8) [0x7f2fe2022ce8] ->
> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f2fe1fc102e] ->
> /usr/lib/dovecot/libdovecot-storage.so.0(mdbox_map_append_move+0x1ed)
> [0x7f2fe2301c0d] ->
> /usr/lib/dovecot/libdovecot-storage.so.0(mdbox_purge+0xfe3)
> [0x7f2fe2303103] -> doveadm(+0x29458) [0x7f2fe2c7e458] ->
> doveadm(+0x2910f) [0x7f2fe2c7e10f] -> doveadm(+0x29db4)
> [0x7f2fe2c7edb4] ->
> doveadm(doveadm_cmd_ver2_to_mail_cmd_wrapper+0x278) [0x7f2fe2c7fae8]
> -> doveadm(doveadm_cmd_run_ver2+0x560) [0x7f2fe2c8dfd0] ->
> doveadm(doveadm_cmd_try_run_ver2+0x37) [0x7f2fe2c8e027] ->
> doveadm(main+0x1e4) [0x7f2fe2c6f414] ->
> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5)
> [0x7f2fe1c0bb45] -> doveadm(+0x1a7ee) [0x7f2fe2c6f7ee]
>
> The command was run in a cleanup script that expunge old mails from
> the lazy-plugin.
> ----
> #!/bin/sh
>
> # Permanently expunge old Trash
> doveadm expunge -A -d mailbox '#EXPUNGED/*' savedbefore 2w
>
> # Optimize mdbox storage and sis storage
> doveadm purge -A
> ----
>
> After rerunning the command it fails again.
>
> stace could be found after config.
>
>
> config:
> # 2.2.devel (6d2fa6b): /etc/dovecot/dovecot.conf
> # Pigeonhole version 0.4.devel (3f51b82)
> # OS: Linux 3.16.0-4-amd64 x86_64 Debian 8.5
> auth_cache_negative_ttl = 1 secs
> auth_cache_size = 10 M
> auth_cache_ttl = 1 secs
> auth_mechanisms = PLAIN LOGIN DIGEST-MD5 SCRAM-SHA-1 CRAM-MD5 APOP
> auth_verbose = yes
> default_client_limit = 600
> default_vsz_limit = 512 M
> dict {
>   lastlogin = mysql:/etc/dovecot/dovecot-dict-sql.conf.ext
>   sqlacl = mysql:/etc/dovecot/dovecot-dict-sql.conf.ext
>   sqlquota = mysql:/etc/dovecot/dovecot-dict-sql.conf.ext
> }
> disable_plaintext_auth = no
> first_valid_gid = 1001
> first_valid_uid = 1001
> hostname = mailstore1 at itronic.at
> imap_hibernate_timeout = 1 mins
> imap_id_log = *
> imap_id_send = *
> imap_idle_notify_interval = 10 mins
> instance_name = mailstore1
> last_valid_gid = 1001
> last_valid_uid = 1001
> lda_original_recipient_header = X-LDA-Original-To
> lmtp_rcpt_check_quota = yes
> login_greeting = ITronic Mail Store
> login_trusted_networks = 172.22.14.0/24
> mail_attachment_dir = /srv/storage1/vmail_sis
> mail_attachment_hash = %{sha512}
> mail_attachment_min_size = 64 k
> mail_cache_min_mail_count = 5
> mail_gid = vmail
> mail_location = mdbox:~/mdbox
> mail_plugins = zlib lazy_expunge stats acl quota
> mail_prefetch_count = 100
> mail_server_admin = mailto:postmaster at itronic.at
> mail_server_comment = ITronic Mail System
> mail_shared_explicit_inbox = yes
> mail_uid = vmail
> mailbox_list_index = 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 index ihave duplicate mime foreverypart
> extracttext
> mdbox_preallocate_space = yes
> namespace {
>   hidden = yes
>   list = no
>   location = mdbox:~/mdbox:MAILBOXDIR=expunged
>   prefix = "#EXPUNGED/"
>   subscriptions = no
>   type = private
> }
> namespace {
>   list = children
>   location = mdbox:%%h/mdbox
>   prefix = "#Users/%%u/"
>   separator = /
>   subscriptions = yes
>   type = shared
> }
> namespace inbox {
>   hidden = no
>   inbox = yes
>   location >   mailbox Archvie {
>     special_use = \Archive
>   }
>   mailbox Drafts {
>     special_use = \Drafts
>   }
>   mailbox Sent {
>     special_use = \Sent
>   }
>   mailbox Spam {
>     special_use = \Junk
>   }
>   mailbox Trash {
>     special_use = \Trash
>   }
>   prefix >   separator = /
>   subscriptions = yes
>   type = private
> }
> passdb {
>   args = /etc/dovecot/dovecot-sql.conf.ext
>   driver = sql
> }
> plugin {
>   acl = vfile
>   acl_shared_dict = proxy::sqlacl
>   last_login_dict = proxy::lastlogin
>   last_login_key = last-login/%u
>   lazy_expunge = "#EXPUNGED/"
>   lazy_expunge_only_last_instance = no
>   quota = dict:User quota::proxy::sqlquota
>   quota_grace = 10%%
>   quota_rule = *:storage=1024M
>   quota_rule2 = "#EXPUNGED:storage=+100M"
>   quota_warning = storage=100%% quota-warning 100 %u
>   quota_warning2 = storage=95%% quota-warning 95 %u
>   quota_warning3 = storage=80%% quota-warning 80 %u
>   recipient_delimiter = +
>   sieve = file:~/sieve;active=~/.dovecot.sieve
>   sieve_global = /etc/dovecot/sieve
>   sieve_max_actions = 64
>   sieve_max_redirects = 8
>   sieve_max_script_size = 2M
>   sieve_quota_max_scripts = 0
>   sieve_quota_max_storage = 64M
>   stats_refresh = 30 secs
>   stats_track_cmds = yes
>   zlib_save = gz
>   zlib_save_level = 6
> }
> pop3_uidl_duplicates = rename
> protocols = imap lmtp sieve pop3 sieve
> service auth-worker {
>   user = $default_internal_user
> }
> service auth {
>   inet_listener {
>     port = 4180
>   }
>   unix_listener auth-userdb {
>     mode = 0666
>   }
> }
> service dict {
>   unix_listener dict {
>     group = vmail
>     mode = 0666
>   }
> }
> service imap-hibernate {
>   unix_listener imap-hibernate {
>     group = vmail
>     mode = 0666
>   }
> }
> service imap-login {
>   inet_listener imap {
>     port = 143
>   }
>   inet_listener imaps {
>     port = 993
>     ssl = yes
>   }
>   process_min_avail = 1
>   service_count = 0
> }
> service imap {
>   process_limit = 1024
>   unix_listener imap-master {
>     user = dovecot
>   }
>   unix_listener imap {
>     group = vmail
>     mode = 0666
>   }
>   vsz_limit = 512 M
> }
> service lmtp {
>   inet_listener lmtp {
>     address = 172.22.14.135
>     port = 24000
>   }
>   unix_listener lmtp {
>     mode = 0666
>   }
> }
> service managesieve-login {
>   inet_listener sieve {
>     port = 4190
>   }
>   process_min_avail = 0
>   service_count = 1
>   vsz_limit = 64 M
> }
> service managesieve {
>   process_limit = 50
> }
> service pop3-login {
>   inet_listener pop3 {
>     port = 110
>   }
>   inet_listener pop3s {
>     port = 995
>     ssl = yes
>   }
>   process_min_avail = 20
>   service_count = 1
>   vsz_limit = 64 M
> }
> service pop3 {
>   process_limit = 1024
> }
> service quota-warning {
>   executable = script /opt/scripts/quota-warning.sh
>   unix_listener quota-warning {
>     user = vmail
>   }
>   user = dovecot
> }
> service stats {
>   fifo_listener stats-mail {
>     mode = 0600
>     user = vmail
>   }
> }
> shutdown_clients = no
> ssl_cert = </etc/dovecot/private/STAR.itronic.at.pem
> ssl_cipher_list >
ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA:ECDHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES256-SHA256:DHE-RSA-AES128-SHA:DHE-RSA-AES256-SHA:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA:AES256-SHA:DHE-RSA-CAMELLIA128-SHA:DHE-RSA-CAMELLIA256-SHA:CAMELLIA128-SHA:CAMELLIA256-SHA:ECDHE-RSA-DES-CBC3-SHA:DES-CBC3-SHA
> ssl_dh_parameters_length = 2048
> ssl_key = </etc/dovecot/private/STAR.itronic.at.pem
> ssl_options = no_compression
> ssl_prefer_server_ciphers = yes
> ssl_protocols = !SSLv2 !SSLv3
> submission_host = 172.22.14.198
> syslog_facility = local0
> userdb {
>   driver = prefetch
> }
> userdb {
>   args = /etc/dovecot/dovecot-sql.conf.ext
>   driver = sql
> }
> valid_chroot_dirs = /srv/storage1/vmail
> verbose_proctitle = yes
> protocol imap {
>   mail_max_userip_connections = 20
>   mail_plugins = zlib lazy_expunge stats imap_stats quota imap_quota
> acl imap_acl last_login
> }
> protocol lda {
>   mail_plugins = zlib lazy_expunge stats acl sieve quota
> }
> protocol lmtp {
>   mail_plugins = zlib lazy_expunge stats acl sieve quota
> }
> protocol sieve {
>   mail_max_userip_connections = 10
>   managesieve_max_compile_errors = 5
>   managesieve_max_line_length = 65536
> }
> protocol pop3 {
>   mail_max_userip_connections = 10
>   mail_plugins = zlib lazy_expunge stats acl last_login
> }
>
>
>
>
>
>
> strace:
>
> open("/srv/storage1/vmail/itronic/7/mdbox/storage/m.4184",
O_RDWR) = 22
> fstat(22, {st_mode=S_IFREG|0644, st_size=38285, ...}) = 0
> pread(22, "2 M1e C577baa0d\n\1\2N          000"..., 8192, 0) =
8192
> flock(22, LOCK_EX|LOCK_NB)              = 0
> stat("/srv/storage1/vmail/itronic/7/mdbox/storage/m.4184",
> {st_mode=S_IFREG|0644, st_size=38285, ...}) = 0
> fstat(22, {st_mode=S_IFREG|0644, st_size=38285, ...}) = 0
> fstat(22, {st_mode=S_IFREG|0644, st_size=38285, ...}) = 0
> pread(19, "\1\2N          0000000000000BE3\n\37\213"..., 8192,
> 1889547) = 8192
> pwrite(22, "\1\2N          0000000000000BE3\n\37\213"..., 3073,
38285)
> = 3073
>
> ....
>
> pread(19, "\1\2N          00000000000003CA\n\37\213"..., 8192,
> 2095957) = 1078
> pwrite(22, "\n\1\3\nZ1510\nR532d6d69\nV1574\nGc74fb"..., 1094,
244601)
> = 1094
> pwrite(21, "\n\1\3\nZ62903b\nR576a94d0\nV63ea34\nG9"..., 632,
2094401)
> = 632
> fdatasync(21)                           = 0
> pwrite(20, "\n\1\3\nZ44ef\nR523ab092\nV467e\nG524f7"..., 94,
2095470)
> = 94
> fdatasync(20)                           = 0
> pwrite(22, "\n\1\3\nZ73b\nR570f7b1b\nV790\nGa658d91"..., 78,
245695) = 78
> fdatasync(22)                           = 0
>
stat("/srv/storage1/vmail/itronic/7/mdbox/storage/dovecot.map.index.log.2",
> {st_mode=S_IFREG|0644, st_size=37848, ...}) = 0
> alarm(180)                              = 0
> fcntl(17, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = 0
> alarm(0)                                = 180
>
stat("/srv/storage1/vmail/itronic/7/mdbox/storage/dovecot.map.index.log",
> {st_mode=S_IFREG|0644, st_size=5160, ...}) = 0
> fstat(17, {st_mode=S_IFREG|0644, st_size=5160, ...}) = 0
> write(2, "doveadm(lord at itronic.at): Panic:"...,
> 72doveadm(lord at itronic.at): Panic: file mdbox-map.c: line 1359:
unreached
> ) = 72
> open("/usr/lib/dovecot/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = -1
ENOENT
> (No such file or directory)
> open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 23
> fstat(23, {st_mode=S_IFREG|0644, st_size=17246, ...}) = 0
> mmap(NULL, 17246, PROT_READ, MAP_PRIVATE, 23, 0) = 0x7f0033cca000
> close(23)                               = 0
> access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file
or
> directory)
> open("/lib/x86_64-linux-gnu/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) =
23
> read(23,
>
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260*\0\0\0\0\0\0"...,
> 832) = 832
> fstat(23, {st_mode=S_IFREG|0644, st_size=90096, ...}) = 0
> mmap(NULL, 2185952, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE,
> 23, 0) = 0x7f002ed5b000
> mprotect(0x7f002ed71000, 2093056, PROT_NONE) = 0
> mmap(0x7f002ef70000, 4096, PROT_READ|PROT_WRITE,
> MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 23, 0x15000) = 0x7f002ef70000
> close(23)                               = 0
> munmap(0x7f0033cca000, 17246)           = 0
> futex(0x7f0032d9e190, FUTEX_WAKE_PRIVATE, 2147483647) = 0
> futex(0x7f002ef70850, FUTEX_WAKE_PRIVATE, 2147483647) = 0
> write(2, "doveadm(lord at itronic.at): Error:"...,
> 860doveadm(lord at itronic.at): Error: Raw backtrace:
> /usr/lib/dovecot/libdovecot.so.0(+0x8dc6e) [0x7f0032e2dc6e] ->
> /usr/lib/dovecot/libdovecot.so.0(+0x8dce8) [0x7f0032e2dce8] ->
> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f0032dcc02e] ->
> /usr/lib/dovecot/libdovecot-storage.so.0(mdbox_map_append_move+0x1ed)
> [0x7f003310cc0d] ->
> /usr/lib/dovecot/libdovecot-storage.so.0(mdbox_purge+0xfe3)
> [0x7f003310e103] -> doveadm(+0x29458) [0x7f0033a89458] ->
> doveadm(+0x2910f) [0x7f0033a8910f] -> doveadm(+0x29db4)
> [0x7f0033a89db4] ->
> doveadm(doveadm_cmd_ver2_to_mail_cmd_wrapper+0x278) [0x7f0033a8aae8]
> -> doveadm(doveadm_cmd_run_ver2+0x560) [0x7f0033a98fd0] ->
> doveadm(doveadm_cmd_try_run_ver2+0x37) [0x7f0033a99027] ->
> doveadm(main+0x1e4) [0x7f0033a7a414] ->
> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5)
> [0x7f0032a16b45] -> doveadm(+0x1a7ee) [0x7f0033a7a7ee]
> ) = 860
> rt_sigprocmask(SIG_UNBLOCK, [ABRT], NULL, 8) = 0
> tgkill(5682, 5682, SIGABRT)             = 0
> --- SIGABRT {si_signo=SIGABRT, si_code=SI_TKILL, si_pid=5682,
> si_uid=0} ---
> +++ killed by SIGABRT +++
> [1]    5679 abort      strace doveadm purge -A
>
>
>
>

Hi!

I tried replicating your issue but was unable to. Is this issue in any
way reproducable anymore? If yes, can you provide us with output of bt
full from gdb?

Aki Tuomi
Dovecot oy