(I'm not subscribed, please keep me CC'd)
Hi,
since a few months I'm experiencing repeated dovecot crashes. I mostly
see them in the logs, I haven't had any users complain, so I haven't
looked closely until now. I was originally using an older version fro
mDebian and hoped that a newer future version would already fix this,
but I just upgraded to version 1:2.2.32-2 from Debian testing, and the problem
persists.
This crash sometimes happens occasionally, but often happens repeatedly
for some time (presumably a client keeps retrying) but can also be gone
for hours or days (presumably the client no longer connects). I haven't
been able to definitively figure out what client causes this, but based
on the user ID I suspect it is Mail.app on OSX.
I managed to get a core dump, which gave me the stacktrace below. I've also
attached my config file. If any other details are relevant, just ask and I can
squeeze them out of the core dump (but I'd rather not publicly share the
file).
I can probably set up rawlog to capture the actual IMAP session if needed,
though I have no time for that right now.
Gr.
Matthijs
51 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0 __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
#1 0x00007fc5eed9c3fa in __GI_abort () at abort.c:89
#2 0x00007fc5ef1a609a in default_fatal_finish (type=LOG_TYPE_PANIC,
status=status at entry=0) at failures.c:201
#3 0x00007fc5ef1a619a in i_internal_fatal_handler (ctx=0x7ffc553b38d0,
format=<optimized out>, args=<optimized out>) at failures.c:670
#4 0x00007fc5ef136cf8 in i_panic (format=format at entry=0x7fc5ef52e880
"file %s: line %d (%s): assertion failed: (%s)") at failures.c:275
#5 0x00007fc5ef47f998 in mailbox_copy_int (_ctx=_ctx at entry=0x7ffc553b3ab0,
mail=<optimized out>) at mail-storage.c:2473
#6 0x00007fc5ef47f9ff in mailbox_copy (_ctx=_ctx at entry=0x7ffc553b3ab0,
mail=<optimized out>) at mail-storage.c:2489
#7 0x000055bae72a2f5f in fetch_and_copy (copy_count_r=<synthetic
pointer>, src_uidset_r=<synthetic pointer>, search_args=<optimized
out>, src_trans_r=0x7ffc553b3a88, t=<optimized out>, move=<optimized
out>,
cmd=0x55bae816d5e8) at cmd-copy.c:72
#8 cmd_copy_full (cmd=0x55bae816d5e8, move=false) at cmd-copy.c:139
#9 0x000055bae72afd9c in command_exec (cmd=cmd at entry=0x55bae816d5e8) at
imap-commands.c:200
#10 0x000055bae72ae322 in client_command_input (cmd=<optimized out>, cmd
at entry=0x55bae816d5e8) at imap-client.c:1088
#11 0x000055bae72ae3bc in client_command_input (cmd=<optimized out>) at
imap-client.c:1148
#12 0x000055bae72ae77d in client_handle_next_command (remove_io_r=<synthetic
pointer>, client=0x55bae816bcf8) at imap-client.c:1190
#13 client_handle_input (client=0x55bae816bcf8) at imap-client.c:1202
#14 0x000055bae72aeccc in client_input (client=0x55bae816bcf8) at
imap-client.c:1249
#15 0x00007fc5ef1bb742 in io_loop_call_io (io=0x55bae816d4e0) at ioloop.c:599
#16 0x00007fc5ef1bcd8e in io_loop_handler_run_internal (ioloop=ioloop at
entry=0x55bae8153990) at ioloop-epoll.c:223
#17 0x00007fc5ef1bb7d6 in io_loop_handler_run (ioloop=ioloop at
entry=0x55bae8153990) at ioloop.c:648
#18 0x00007fc5ef1bb988 in io_loop_run (ioloop=0x55bae8153990) at ioloop.c:623
#19 0x00007fc5ef141353 in master_service_run (service=0x55bae8153830,
callback=<optimized out>) at master-service.c:666
#20 0x000055bae72a1139 in main (argc=<optimized out>, argv=<optimized
out>) at main.c:491
(gdb) up 9
#9 0x000055bae72afd9c in command_exec (cmd=cmd at entry=0x55bae816d5e8) at
imap-commands.c:200
200 finished = cmd->func(cmd);
(gdb) p *cmd
$14 = {prev = 0x0, next = 0x0, client = 0x55bae816bcf8, pool = 0x55bae816d5c0,
tag = 0x55bae816d750 "7.119309", name = 0x55bae816d760 "UID
COPY", args = 0x55bae816d770 "20004 INBOX",
human_args = 0x55bae816d780 "20004 INBOX", cmd_flags =
COMMAND_FLAG_BREAKS_SEQS, tagline_reply = 0x0, func = 0x55bae72a33e0
<cmd_copy>, context = 0x0, module_contexts = {arr = {buffer =
0x55bae816d6e8,
element_size = 8}, v = 0x55bae816d6e8, v_modifiable = 0x55bae816d6e8},
parser = 0x55bae8157aa0, state = CLIENT_COMMAND_STATE_WAIT_INPUT, stats =
{start_time = {tv_sec = 1506507612, tv_usec = 777163},
last_run_timeval = {tv_sec = 1506507612, tv_usec = 777163},
start_ioloop_wait_usecs = 46340, running_usecs = 0, lock_wait_usecs = 0,
bytes_in = 0, bytes_out = 0}, stats_start = {timeval = {
tv_sec = 1506507612, tv_usec = 777241}, lock_wait_usecs = 0, bytes_in =
91, bytes_out = 852}, sync = 0x0, uid = 1, cancel = 0, param_error = 0,
search_save_result = 0, search_save_result_used = 0,
temp_executed = 0, tagline_sent = 0, executing = 1}
(gdb) down
#8 cmd_copy_full (cmd=0x55bae816d5e8, move=false) at cmd-copy.c:139
139 ret = fetch_and_copy(cmd, move, t, &src_trans, search_args,
(gdb)
#7 0x000055bae72a2f5f in fetch_and_copy (copy_count_r=<synthetic
pointer>, src_uidset_r=<synthetic pointer>, search_args=<optimized
out>, src_trans_r=0x7ffc553b3a88, t=<optimized out>, move=<optimized
out>,
cmd=0x55bae816d5e8) at cmd-copy.c:72
72 if (mailbox_copy(&save_ctx, mail) < 0)
(gdb)
#6 0x00007fc5ef47f9ff in mailbox_copy (_ctx=_ctx at entry=0x7ffc553b3ab0,
mail=<optimized out>) at mail-storage.c:2489
2489 return mailbox_copy_int(_ctx, mail);
(gdb)
#5 0x00007fc5ef47f998 in mailbox_copy_int (_ctx=_ctx at entry=0x7ffc553b3ab0,
mail=<optimized out>) at mail-storage.c:2473
2473 i_assert(!ctx->unfinished);
(gdb)
#4 0x00007fc5ef136cf8 in i_panic (format=format at entry=0x7fc5ef52e880
"file %s: line %d (%s): assertion failed: (%s)") at failures.c:275
275 fatal_handler(&ctx, format, args);
-------------- next part --------------
# 2.2.32 (dfbe293d4): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.4.20 (7cd71ba)
# OS: Linux 4.4.0-1-amd64 x86_64 Debian 9.1
auth_mechanisms = plain login
log_timestamp = "%Y-%m-%d %H:%M:%S "
mail_access_groups = spamd-access
mail_gid = virtual-mail
mail_location = Maildir:~/Folders:INBOX=~/INBOX:LAYOUT=fs
mail_uid = virtual-mail
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
passdb {
args = /etc/dovecot/dovecot-ldap.conf
driver = ldap
}
plugin {
antispam_backend = pipe
antispam_pipe_program = /usr/local/bin/trainspam
antispam_pipe_program_notspam_arg = ham
antispam_pipe_program_spam_arg = spam
antispam_spam = Spam;ProbablySpam;Ongewenste e-mail;Junk
antispam_trash_pattern_ignorecase = trash;Deleted *;Prullenbak;Verwijderde *
antispam_unsure = INBOX
sieve = ~/sieve
sieve_dir = ~/sieve.d
sieve_global_path = /etc/dovecot/sieve/default
}
protocols = imap sieve
service auth {
unix_listener auth-client {
group = Debian-exim
mode = 0600
user = Debian-exim
}
unix_listener auth-master {
group = virtual-mail
mode = 0600
user = virtual-mail
}
user = nobody
}
ssl_cert = </etc/letsencrypt/live/tikatika.nl/fullchain.pem
ssl_key = # hidden, use -P to show it
userdb {
args = home=/data/mail/%u allow_all_users=yes uid=virtual-mail
gid=virtual-mail
driver = static
}
protocol imap {
mail_plugins = antispam
}
protocol lda {
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
mail_plugins = sieve
postmaster_address =
}
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: not available
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20170927/29aa4cb2/attachment.sig>
Matthijs Kooijman
2017-Sep-27 12:36 UTC
mail-storage.c:2473 assertion failed: (!ctx->unfinished) (related to antispam?)
Hey folks, apologies for the useless subject on my original mail, forgot to update it. Two more bits of info. Here's the log output related to this crash: dovecot: imap-login: Login: user=<2014>, method=PLAIN, rip=217.122.126.195, lip=10.42.0.13, mpid=10569, TLS, session=<IsP37ypaFYHZen7D> dovecot: imap(2014): Panic: file mail-storage.c: line 2473 (mailbox_copy_int): assertion failed: (!ctx->unfinished) (I've omitted the raw backtrace) And, I just discovered that (it seems that) whenever such a crash happens, an empty /tmp/antispam-mail-xyz directory is created, which makes me suspect that at least the antispam plugin is involved in these imap sessions, and might the the one causing the crash. I'm running the latest antispam version from Debian (2.0+20170109-1+b2, which also seems to be the latest upstream). Gr. Matthijs On Wed, Sep 27, 2017 at 02:21:09PM +0200, Matthijs Kooijman wrote:> (I'm not subscribed, please keep me CC'd) > > Hi, > > since a few months I'm experiencing repeated dovecot crashes. I mostly > see them in the logs, I haven't had any users complain, so I haven't > looked closely until now. I was originally using an older version fro > mDebian and hoped that a newer future version would already fix this, > but I just upgraded to version 1:2.2.32-2 from Debian testing, and the problem > persists. > > This crash sometimes happens occasionally, but often happens repeatedly > for some time (presumably a client keeps retrying) but can also be gone > for hours or days (presumably the client no longer connects). I haven't > been able to definitively figure out what client causes this, but based > on the user ID I suspect it is Mail.app on OSX. > > I managed to get a core dump, which gave me the stacktrace below. I've also > attached my config file. If any other details are relevant, just ask and I can > squeeze them out of the core dump (but I'd rather not publicly share the file). > I can probably set up rawlog to capture the actual IMAP session if needed, > though I have no time for that right now. > > Gr. > > Matthijs > > 51 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory. > (gdb) bt > #0 __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51 > #1 0x00007fc5eed9c3fa in __GI_abort () at abort.c:89 > #2 0x00007fc5ef1a609a in default_fatal_finish (type=LOG_TYPE_PANIC, status=status at entry=0) at failures.c:201 > #3 0x00007fc5ef1a619a in i_internal_fatal_handler (ctx=0x7ffc553b38d0, format=<optimized out>, args=<optimized out>) at failures.c:670 > #4 0x00007fc5ef136cf8 in i_panic (format=format at entry=0x7fc5ef52e880 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:275 > #5 0x00007fc5ef47f998 in mailbox_copy_int (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2473 > #6 0x00007fc5ef47f9ff in mailbox_copy (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2489 > #7 0x000055bae72a2f5f in fetch_and_copy (copy_count_r=<synthetic pointer>, src_uidset_r=<synthetic pointer>, search_args=<optimized out>, src_trans_r=0x7ffc553b3a88, t=<optimized out>, move=<optimized out>, > cmd=0x55bae816d5e8) at cmd-copy.c:72 > #8 cmd_copy_full (cmd=0x55bae816d5e8, move=false) at cmd-copy.c:139 > #9 0x000055bae72afd9c in command_exec (cmd=cmd at entry=0x55bae816d5e8) at imap-commands.c:200 > #10 0x000055bae72ae322 in client_command_input (cmd=<optimized out>, cmd at entry=0x55bae816d5e8) at imap-client.c:1088 > #11 0x000055bae72ae3bc in client_command_input (cmd=<optimized out>) at imap-client.c:1148 > #12 0x000055bae72ae77d in client_handle_next_command (remove_io_r=<synthetic pointer>, client=0x55bae816bcf8) at imap-client.c:1190 > #13 client_handle_input (client=0x55bae816bcf8) at imap-client.c:1202 > #14 0x000055bae72aeccc in client_input (client=0x55bae816bcf8) at imap-client.c:1249 > #15 0x00007fc5ef1bb742 in io_loop_call_io (io=0x55bae816d4e0) at ioloop.c:599 > #16 0x00007fc5ef1bcd8e in io_loop_handler_run_internal (ioloop=ioloop at entry=0x55bae8153990) at ioloop-epoll.c:223 > #17 0x00007fc5ef1bb7d6 in io_loop_handler_run (ioloop=ioloop at entry=0x55bae8153990) at ioloop.c:648 > #18 0x00007fc5ef1bb988 in io_loop_run (ioloop=0x55bae8153990) at ioloop.c:623 > #19 0x00007fc5ef141353 in master_service_run (service=0x55bae8153830, callback=<optimized out>) at master-service.c:666 > #20 0x000055bae72a1139 in main (argc=<optimized out>, argv=<optimized out>) at main.c:491 > (gdb) up 9 > #9 0x000055bae72afd9c in command_exec (cmd=cmd at entry=0x55bae816d5e8) at imap-commands.c:200 > 200 finished = cmd->func(cmd); > (gdb) p *cmd > $14 = {prev = 0x0, next = 0x0, client = 0x55bae816bcf8, pool = 0x55bae816d5c0, tag = 0x55bae816d750 "7.119309", name = 0x55bae816d760 "UID COPY", args = 0x55bae816d770 "20004 INBOX", > human_args = 0x55bae816d780 "20004 INBOX", cmd_flags = COMMAND_FLAG_BREAKS_SEQS, tagline_reply = 0x0, func = 0x55bae72a33e0 <cmd_copy>, context = 0x0, module_contexts = {arr = {buffer = 0x55bae816d6e8, > element_size = 8}, v = 0x55bae816d6e8, v_modifiable = 0x55bae816d6e8}, parser = 0x55bae8157aa0, state = CLIENT_COMMAND_STATE_WAIT_INPUT, stats = {start_time = {tv_sec = 1506507612, tv_usec = 777163}, > last_run_timeval = {tv_sec = 1506507612, tv_usec = 777163}, start_ioloop_wait_usecs = 46340, running_usecs = 0, lock_wait_usecs = 0, bytes_in = 0, bytes_out = 0}, stats_start = {timeval = { > tv_sec = 1506507612, tv_usec = 777241}, lock_wait_usecs = 0, bytes_in = 91, bytes_out = 852}, sync = 0x0, uid = 1, cancel = 0, param_error = 0, search_save_result = 0, search_save_result_used = 0, > temp_executed = 0, tagline_sent = 0, executing = 1} > (gdb) down > #8 cmd_copy_full (cmd=0x55bae816d5e8, move=false) at cmd-copy.c:139 > 139 ret = fetch_and_copy(cmd, move, t, &src_trans, search_args, > (gdb) > #7 0x000055bae72a2f5f in fetch_and_copy (copy_count_r=<synthetic pointer>, src_uidset_r=<synthetic pointer>, search_args=<optimized out>, src_trans_r=0x7ffc553b3a88, t=<optimized out>, move=<optimized out>, > cmd=0x55bae816d5e8) at cmd-copy.c:72 > 72 if (mailbox_copy(&save_ctx, mail) < 0) > (gdb) > #6 0x00007fc5ef47f9ff in mailbox_copy (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2489 > 2489 return mailbox_copy_int(_ctx, mail); > (gdb) > #5 0x00007fc5ef47f998 in mailbox_copy_int (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2473 > 2473 i_assert(!ctx->unfinished); > (gdb) > #4 0x00007fc5ef136cf8 in i_panic (format=format at entry=0x7fc5ef52e880 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:275 > 275 fatal_handler(&ctx, format, args); >> # 2.2.32 (dfbe293d4): /etc/dovecot/dovecot.conf > # Pigeonhole version 0.4.20 (7cd71ba) > # OS: Linux 4.4.0-1-amd64 x86_64 Debian 9.1 > auth_mechanisms = plain login > log_timestamp = "%Y-%m-%d %H:%M:%S " > mail_access_groups = spamd-access > mail_gid = virtual-mail > mail_location = Maildir:~/Folders:INBOX=~/INBOX:LAYOUT=fs > mail_uid = virtual-mail > 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 > passdb { > args = /etc/dovecot/dovecot-ldap.conf > driver = ldap > } > plugin { > antispam_backend = pipe > antispam_pipe_program = /usr/local/bin/trainspam > antispam_pipe_program_notspam_arg = ham > antispam_pipe_program_spam_arg = spam > antispam_spam = Spam;ProbablySpam;Ongewenste e-mail;Junk > antispam_trash_pattern_ignorecase = trash;Deleted *;Prullenbak;Verwijderde * > antispam_unsure = INBOX > sieve = ~/sieve > sieve_dir = ~/sieve.d > sieve_global_path = /etc/dovecot/sieve/default > } > protocols = imap sieve > service auth { > unix_listener auth-client { > group = Debian-exim > mode = 0600 > user = Debian-exim > } > unix_listener auth-master { > group = virtual-mail > mode = 0600 > user = virtual-mail > } > user = nobody > } > ssl_cert = </etc/letsencrypt/live/tikatika.nl/fullchain.pem > ssl_key = # hidden, use -P to show it > userdb { > args = home=/data/mail/%u allow_all_users=yes uid=virtual-mail gid=virtual-mail > driver = static > } > protocol imap { > mail_plugins = antispam > } > protocol lda { > lda_mailbox_autocreate = yes > lda_mailbox_autosubscribe = yes > mail_plugins = sieve > postmaster_address = > }-------------- next part -------------- A non-text attachment was scrubbed... Name: signature.asc Type: application/pgp-signature Size: 833 bytes Desc: not available URL: <https://dovecot.org/pipermail/dovecot/attachments/20170927/03476e56/attachment.sig>
Stephan Bosch
2017-Sep-27 12:44 UTC
mail-storage.c:2473 assertion failed: (!ctx->unfinished) (related to antispam?)
Op 9/27/2017 om 2:36 PM schreef Matthijs Kooijman:> Hey folks, > > apologies for the useless subject on my original mail, forgot to update > it. > > Two more bits of info. Here's the log output related to this crash: > > dovecot: imap-login: Login: user=<2014>, method=PLAIN, rip=217.122.126.195, lip=10.42.0.13, mpid=10569, TLS, session=<IsP37ypaFYHZen7D> > dovecot: imap(2014): Panic: file mail-storage.c: line 2473 (mailbox_copy_int): assertion failed: (!ctx->unfinished) > (I've omitted the raw backtrace) > > And, I just discovered that (it seems that) whenever such a crash > happens, an empty /tmp/antispam-mail-xyz directory is created, which > makes me suspect that at least the antispam plugin is involved in these > imap sessions, and might the the one causing the crash. I'm running the > latest antispam version from Debian (2.0+20170109-1+b2, which also seems > to be the latest upstream).That sounds plausible. However, since you're using a very recent Dovecot now, you should consider using IMAPSieve instead: https://wiki2.dovecot.org/HowTo/AntispamWithSieve Regards, Stephan.> > Gr. > > Matthijs > > > On Wed, Sep 27, 2017 at 02:21:09PM +0200, Matthijs Kooijman wrote: >> (I'm not subscribed, please keep me CC'd) >> >> Hi, >> >> since a few months I'm experiencing repeated dovecot crashes. I mostly >> see them in the logs, I haven't had any users complain, so I haven't >> looked closely until now. I was originally using an older version fro >> mDebian and hoped that a newer future version would already fix this, >> but I just upgraded to version 1:2.2.32-2 from Debian testing, and the problem >> persists. >> >> This crash sometimes happens occasionally, but often happens repeatedly >> for some time (presumably a client keeps retrying) but can also be gone >> for hours or days (presumably the client no longer connects). I haven't >> been able to definitively figure out what client causes this, but based >> on the user ID I suspect it is Mail.app on OSX. >> >> I managed to get a core dump, which gave me the stacktrace below. I've also >> attached my config file. If any other details are relevant, just ask and I can >> squeeze them out of the core dump (but I'd rather not publicly share the file). >> I can probably set up rawlog to capture the actual IMAP session if needed, >> though I have no time for that right now. >> >> Gr. >> >> Matthijs >> >> 51 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory. >> (gdb) bt >> #0 __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51 >> #1 0x00007fc5eed9c3fa in __GI_abort () at abort.c:89 >> #2 0x00007fc5ef1a609a in default_fatal_finish (type=LOG_TYPE_PANIC, status=status at entry=0) at failures.c:201 >> #3 0x00007fc5ef1a619a in i_internal_fatal_handler (ctx=0x7ffc553b38d0, format=<optimized out>, args=<optimized out>) at failures.c:670 >> #4 0x00007fc5ef136cf8 in i_panic (format=format at entry=0x7fc5ef52e880 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:275 >> #5 0x00007fc5ef47f998 in mailbox_copy_int (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2473 >> #6 0x00007fc5ef47f9ff in mailbox_copy (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2489 >> #7 0x000055bae72a2f5f in fetch_and_copy (copy_count_r=<synthetic pointer>, src_uidset_r=<synthetic pointer>, search_args=<optimized out>, src_trans_r=0x7ffc553b3a88, t=<optimized out>, move=<optimized out>, >> cmd=0x55bae816d5e8) at cmd-copy.c:72 >> #8 cmd_copy_full (cmd=0x55bae816d5e8, move=false) at cmd-copy.c:139 >> #9 0x000055bae72afd9c in command_exec (cmd=cmd at entry=0x55bae816d5e8) at imap-commands.c:200 >> #10 0x000055bae72ae322 in client_command_input (cmd=<optimized out>, cmd at entry=0x55bae816d5e8) at imap-client.c:1088 >> #11 0x000055bae72ae3bc in client_command_input (cmd=<optimized out>) at imap-client.c:1148 >> #12 0x000055bae72ae77d in client_handle_next_command (remove_io_r=<synthetic pointer>, client=0x55bae816bcf8) at imap-client.c:1190 >> #13 client_handle_input (client=0x55bae816bcf8) at imap-client.c:1202 >> #14 0x000055bae72aeccc in client_input (client=0x55bae816bcf8) at imap-client.c:1249 >> #15 0x00007fc5ef1bb742 in io_loop_call_io (io=0x55bae816d4e0) at ioloop.c:599 >> #16 0x00007fc5ef1bcd8e in io_loop_handler_run_internal (ioloop=ioloop at entry=0x55bae8153990) at ioloop-epoll.c:223 >> #17 0x00007fc5ef1bb7d6 in io_loop_handler_run (ioloop=ioloop at entry=0x55bae8153990) at ioloop.c:648 >> #18 0x00007fc5ef1bb988 in io_loop_run (ioloop=0x55bae8153990) at ioloop.c:623 >> #19 0x00007fc5ef141353 in master_service_run (service=0x55bae8153830, callback=<optimized out>) at master-service.c:666 >> #20 0x000055bae72a1139 in main (argc=<optimized out>, argv=<optimized out>) at main.c:491 >> (gdb) up 9 >> #9 0x000055bae72afd9c in command_exec (cmd=cmd at entry=0x55bae816d5e8) at imap-commands.c:200 >> 200 finished = cmd->func(cmd); >> (gdb) p *cmd >> $14 = {prev = 0x0, next = 0x0, client = 0x55bae816bcf8, pool = 0x55bae816d5c0, tag = 0x55bae816d750 "7.119309", name = 0x55bae816d760 "UID COPY", args = 0x55bae816d770 "20004 INBOX", >> human_args = 0x55bae816d780 "20004 INBOX", cmd_flags = COMMAND_FLAG_BREAKS_SEQS, tagline_reply = 0x0, func = 0x55bae72a33e0 <cmd_copy>, context = 0x0, module_contexts = {arr = {buffer = 0x55bae816d6e8, >> element_size = 8}, v = 0x55bae816d6e8, v_modifiable = 0x55bae816d6e8}, parser = 0x55bae8157aa0, state = CLIENT_COMMAND_STATE_WAIT_INPUT, stats = {start_time = {tv_sec = 1506507612, tv_usec = 777163}, >> last_run_timeval = {tv_sec = 1506507612, tv_usec = 777163}, start_ioloop_wait_usecs = 46340, running_usecs = 0, lock_wait_usecs = 0, bytes_in = 0, bytes_out = 0}, stats_start = {timeval = { >> tv_sec = 1506507612, tv_usec = 777241}, lock_wait_usecs = 0, bytes_in = 91, bytes_out = 852}, sync = 0x0, uid = 1, cancel = 0, param_error = 0, search_save_result = 0, search_save_result_used = 0, >> temp_executed = 0, tagline_sent = 0, executing = 1} >> (gdb) down >> #8 cmd_copy_full (cmd=0x55bae816d5e8, move=false) at cmd-copy.c:139 >> 139 ret = fetch_and_copy(cmd, move, t, &src_trans, search_args, >> (gdb) >> #7 0x000055bae72a2f5f in fetch_and_copy (copy_count_r=<synthetic pointer>, src_uidset_r=<synthetic pointer>, search_args=<optimized out>, src_trans_r=0x7ffc553b3a88, t=<optimized out>, move=<optimized out>, >> cmd=0x55bae816d5e8) at cmd-copy.c:72 >> 72 if (mailbox_copy(&save_ctx, mail) < 0) >> (gdb) >> #6 0x00007fc5ef47f9ff in mailbox_copy (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2489 >> 2489 return mailbox_copy_int(_ctx, mail); >> (gdb) >> #5 0x00007fc5ef47f998 in mailbox_copy_int (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2473 >> 2473 i_assert(!ctx->unfinished); >> (gdb) >> #4 0x00007fc5ef136cf8 in i_panic (format=format at entry=0x7fc5ef52e880 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:275 >> 275 fatal_handler(&ctx, format, args); >> >> # 2.2.32 (dfbe293d4): /etc/dovecot/dovecot.conf >> # Pigeonhole version 0.4.20 (7cd71ba) >> # OS: Linux 4.4.0-1-amd64 x86_64 Debian 9.1 >> auth_mechanisms = plain login >> log_timestamp = "%Y-%m-%d %H:%M:%S " >> mail_access_groups = spamd-access >> mail_gid = virtual-mail >> mail_location = Maildir:~/Folders:INBOX=~/INBOX:LAYOUT=fs >> mail_uid = virtual-mail >> 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 >> passdb { >> args = /etc/dovecot/dovecot-ldap.conf >> driver = ldap >> } >> plugin { >> antispam_backend = pipe >> antispam_pipe_program = /usr/local/bin/trainspam >> antispam_pipe_program_notspam_arg = ham >> antispam_pipe_program_spam_arg = spam >> antispam_spam = Spam;ProbablySpam;Ongewenste e-mail;Junk >> antispam_trash_pattern_ignorecase = trash;Deleted *;Prullenbak;Verwijderde * >> antispam_unsure = INBOX >> sieve = ~/sieve >> sieve_dir = ~/sieve.d >> sieve_global_path = /etc/dovecot/sieve/default >> } >> protocols = imap sieve >> service auth { >> unix_listener auth-client { >> group = Debian-exim >> mode = 0600 >> user = Debian-exim >> } >> unix_listener auth-master { >> group = virtual-mail >> mode = 0600 >> user = virtual-mail >> } >> user = nobody >> } >> ssl_cert = </etc/letsencrypt/live/tikatika.nl/fullchain.pem >> ssl_key = # hidden, use -P to show it >> userdb { >> args = home=/data/mail/%u allow_all_users=yes uid=virtual-mail gid=virtual-mail >> driver = static >> } >> protocol imap { >> mail_plugins = antispam >> } >> protocol lda { >> lda_mailbox_autocreate = yes >> lda_mailbox_autosubscribe = yes >> mail_plugins = sieve >> postmaster_address = >> } > >
Can you please include excerpt of your logs too? There should be "Panic: ..something..." there. also bt full is more useful than just bt. Aki On 27.09.2017 15:21, Matthijs Kooijman wrote:> (I'm not subscribed, please keep me CC'd) > > Hi, > > since a few months I'm experiencing repeated dovecot crashes. I mostly > see them in the logs, I haven't had any users complain, so I haven't > looked closely until now. I was originally using an older version fro > mDebian and hoped that a newer future version would already fix this, > but I just upgraded to version 1:2.2.32-2 from Debian testing, and the problem > persists. > > This crash sometimes happens occasionally, but often happens repeatedly > for some time (presumably a client keeps retrying) but can also be gone > for hours or days (presumably the client no longer connects). I haven't > been able to definitively figure out what client causes this, but based > on the user ID I suspect it is Mail.app on OSX. > > I managed to get a core dump, which gave me the stacktrace below. I've also > attached my config file. If any other details are relevant, just ask and I can > squeeze them out of the core dump (but I'd rather not publicly share the file). > I can probably set up rawlog to capture the actual IMAP session if needed, > though I have no time for that right now. > > Gr. > > Matthijs > > 51 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory. > (gdb) bt > #0 __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51 > #1 0x00007fc5eed9c3fa in __GI_abort () at abort.c:89 > #2 0x00007fc5ef1a609a in default_fatal_finish (type=LOG_TYPE_PANIC, status=status at entry=0) at failures.c:201 > #3 0x00007fc5ef1a619a in i_internal_fatal_handler (ctx=0x7ffc553b38d0, format=<optimized out>, args=<optimized out>) at failures.c:670 > #4 0x00007fc5ef136cf8 in i_panic (format=format at entry=0x7fc5ef52e880 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:275 > #5 0x00007fc5ef47f998 in mailbox_copy_int (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2473 > #6 0x00007fc5ef47f9ff in mailbox_copy (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2489 > #7 0x000055bae72a2f5f in fetch_and_copy (copy_count_r=<synthetic pointer>, src_uidset_r=<synthetic pointer>, search_args=<optimized out>, src_trans_r=0x7ffc553b3a88, t=<optimized out>, move=<optimized out>, > cmd=0x55bae816d5e8) at cmd-copy.c:72 > #8 cmd_copy_full (cmd=0x55bae816d5e8, move=false) at cmd-copy.c:139 > #9 0x000055bae72afd9c in command_exec (cmd=cmd at entry=0x55bae816d5e8) at imap-commands.c:200 > #10 0x000055bae72ae322 in client_command_input (cmd=<optimized out>, cmd at entry=0x55bae816d5e8) at imap-client.c:1088 > #11 0x000055bae72ae3bc in client_command_input (cmd=<optimized out>) at imap-client.c:1148 > #12 0x000055bae72ae77d in client_handle_next_command (remove_io_r=<synthetic pointer>, client=0x55bae816bcf8) at imap-client.c:1190 > #13 client_handle_input (client=0x55bae816bcf8) at imap-client.c:1202 > #14 0x000055bae72aeccc in client_input (client=0x55bae816bcf8) at imap-client.c:1249 > #15 0x00007fc5ef1bb742 in io_loop_call_io (io=0x55bae816d4e0) at ioloop.c:599 > #16 0x00007fc5ef1bcd8e in io_loop_handler_run_internal (ioloop=ioloop at entry=0x55bae8153990) at ioloop-epoll.c:223 > #17 0x00007fc5ef1bb7d6 in io_loop_handler_run (ioloop=ioloop at entry=0x55bae8153990) at ioloop.c:648 > #18 0x00007fc5ef1bb988 in io_loop_run (ioloop=0x55bae8153990) at ioloop.c:623 > #19 0x00007fc5ef141353 in master_service_run (service=0x55bae8153830, callback=<optimized out>) at master-service.c:666 > #20 0x000055bae72a1139 in main (argc=<optimized out>, argv=<optimized out>) at main.c:491 > (gdb) up 9 > #9 0x000055bae72afd9c in command_exec (cmd=cmd at entry=0x55bae816d5e8) at imap-commands.c:200 > 200 finished = cmd->func(cmd); > (gdb) p *cmd > $14 = {prev = 0x0, next = 0x0, client = 0x55bae816bcf8, pool = 0x55bae816d5c0, tag = 0x55bae816d750 "7.119309", name = 0x55bae816d760 "UID COPY", args = 0x55bae816d770 "20004 INBOX", > human_args = 0x55bae816d780 "20004 INBOX", cmd_flags = COMMAND_FLAG_BREAKS_SEQS, tagline_reply = 0x0, func = 0x55bae72a33e0 <cmd_copy>, context = 0x0, module_contexts = {arr = {buffer = 0x55bae816d6e8, > element_size = 8}, v = 0x55bae816d6e8, v_modifiable = 0x55bae816d6e8}, parser = 0x55bae8157aa0, state = CLIENT_COMMAND_STATE_WAIT_INPUT, stats = {start_time = {tv_sec = 1506507612, tv_usec = 777163}, > last_run_timeval = {tv_sec = 1506507612, tv_usec = 777163}, start_ioloop_wait_usecs = 46340, running_usecs = 0, lock_wait_usecs = 0, bytes_in = 0, bytes_out = 0}, stats_start = {timeval = { > tv_sec = 1506507612, tv_usec = 777241}, lock_wait_usecs = 0, bytes_in = 91, bytes_out = 852}, sync = 0x0, uid = 1, cancel = 0, param_error = 0, search_save_result = 0, search_save_result_used = 0, > temp_executed = 0, tagline_sent = 0, executing = 1} > (gdb) down > #8 cmd_copy_full (cmd=0x55bae816d5e8, move=false) at cmd-copy.c:139 > 139 ret = fetch_and_copy(cmd, move, t, &src_trans, search_args, > (gdb) > #7 0x000055bae72a2f5f in fetch_and_copy (copy_count_r=<synthetic pointer>, src_uidset_r=<synthetic pointer>, search_args=<optimized out>, src_trans_r=0x7ffc553b3a88, t=<optimized out>, move=<optimized out>, > cmd=0x55bae816d5e8) at cmd-copy.c:72 > 72 if (mailbox_copy(&save_ctx, mail) < 0) > (gdb) > #6 0x00007fc5ef47f9ff in mailbox_copy (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2489 > 2489 return mailbox_copy_int(_ctx, mail); > (gdb) > #5 0x00007fc5ef47f998 in mailbox_copy_int (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2473 > 2473 i_assert(!ctx->unfinished); > (gdb) > #4 0x00007fc5ef136cf8 in i_panic (format=format at entry=0x7fc5ef52e880 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:275 > 275 fatal_handler(&ctx, format, args); >
Hey Aki,> Can you please include excerpt of your logs too? There should be "Panic: > ..something..." there.I just sent those over in a reply on my original mail. Also note that dovecot-antispam seems to be involved somehow, as noted in that mail.> also bt full is more useful than just bt.Learn something new every day. Thanks! Full trace below. Gr. Matthijs #0 __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51 set = {__val = {0, 140488096882154, 206158430240, 2048, 140721738430152, 94261245951216, 2048, 140488096750978, 1132, 1123, 94261245951216, 8, 1123, 140488096765532, 1124, 4011657404}} pid = <optimized out> tid = <optimized out> #1 0x00007fc5eed9c3fa in __GI_abort () at abort.c:89 save_stage = 2 act = {__sigaction_handler = {sa_handler = 0x2f746f6365766f64, sa_sigaction = 0x2f746f6365766f64}, sa_mask = {__val = {8391155158010129769, 181, 4011657404, 140721738430480, 513, 513, 140488096760763, 94261245949088, 4334582184549825280, 512, 140488096941506, 140721738430592, 94261245949088, 140721738430592, 140488096941881, 94261245949088}}, sa_flags = -283504838, sa_restorer = 0x5} sigs = {__val = {32, 0 <repeats 15 times>}} #2 0x00007fc5ef1a609a in default_fatal_finish (type=LOG_TYPE_PANIC, status=status at entry=0) at failures.c:201 backtrace = 0x55bae814b4d8 "/usr/lib/dovecot/libdovecot.so.0(+0x9f0a2) [0x7fc5ef1a60a2] -> /usr/lib/dovecot/libdovecot.so.0(+0x9f19a) [0x7fc5ef1a619a] -> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7fc5ef136cf8] -> /usr/lib/d"... #3 0x00007fc5ef1a619a in i_internal_fatal_handler (ctx=0x7ffc553b38d0, format=<optimized out>, args=<optimized out>) at failures.c:670 status = 0 #4 0x00007fc5ef136cf8 in i_panic (format=format at entry=0x7fc5ef52e880 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:275 ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0, timestamp_usecs = 0} args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area = 0x7ffc553b39d0, reg_save_area = 0x7ffc553b3910}} #5 0x00007fc5ef47f998 in mailbox_copy_int (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2473 ctx = 0x55bae8184e58 t = 0x55bae817e710 keywords = 0x0 pvt_flags = 0 backend_mail = 0x55bae8180638 ret = -1 __FUNCTION__ = "mailbox_copy_int" #6 0x00007fc5ef47f9ff in mailbox_copy (_ctx=_ctx at entry=0x7ffc553b3ab0, mail=<optimized out>) at mail-storage.c:2489 ctx = <optimized out> __FUNCTION__ = "mailbox_copy" #7 0x000055bae72a2f5f in fetch_and_copy (copy_count_r=<synthetic pointer>, src_uidset_r=<synthetic pointer>, search_args=<optimized out>, src_trans_r=0x7ffc553b3a88, t=<optimized out>, move=<optimized out>, cmd=0x55bae816d5e8) at cmd-copy.c:72 search_ctx = 0x55bae8180370 src_trans = 0x55bae817f530 srcset_ctx = {str = 0x55bae814b330, first_uid = 0, last_uid = 4294967295} ret = 1 client = <optimized out> save_ctx = 0x0 mail = 0x55bae8180638 copy_count = 1 src_uidset = 0x55bae814b330 #8 cmd_copy_full (cmd=0x55bae816d5e8, move=false) at cmd-copy.c:139 client = 0x55bae816bcf8 dest_storage = <optimized out> destbox = 0x55bae81780b8 t = 0x55bae817e710 src_trans = 0x55bae816d5c0 search_args = 0x55bae81770a8 messageset = 0x55bae8157d58 "20004" mailbox = 0x55bae8157d60 "INBOX" src_uidset = <optimized out> sync_flags = (unknown: 0) imap_flags = (unknown: 0) changes = {pool = 0x55bae814b330, uid_validity = 0, saved_uids = {arr = {buffer = 0x7ffc553b3b10, element_size = 140721738530399}, v = 0x7ffc553b3b10, v_modifiable = 0x7ffc553b3b10}, ignored_modseq_changes = 0, changed = false, no_read_perm = false} msg = <optimized out> ret = <optimized out> __FUNCTION__ = "cmd_copy_full" #9 0x000055bae72afd9c in command_exec (cmd=cmd at entry=0x55bae816d5e8) at imap-commands.c:200 hook = 0x55bae8154360 finished = <optimized out> __FUNCTION__ = "command_exec" #10 0x000055bae72ae322 in client_command_input (cmd=<optimized out>, cmd at entry=0x55bae816d5e8) at imap-client.c:1088 client = 0x55bae816bcf8 command = <optimized out> __FUNCTION__ = "client_command_input" #11 0x000055bae72ae3bc in client_command_input (cmd=<optimized out>) at imap-client.c:1148 client = 0x55bae816bcf8 command = <optimized out> __FUNCTION__ = "client_command_input" #12 0x000055bae72ae77d in client_handle_next_command (remove_io_r=<synthetic pointer>, client=0x55bae816bcf8) at imap-client.c:1190 No locals. #13 client_handle_input (client=0x55bae816bcf8) at imap-client.c:1202 _data_stack_cur_id = 3 remove_io = false client = 0x55bae816bcf8 #14 0x000055bae72aeccc in client_input (client=0x55bae816bcf8) at imap-client.c:1249 cmd = 0xbdbcb output = 0x55bae816d410 bytes = 31 __FUNCTION__ = "client_input" #15 0x00007fc5ef1bb742 in io_loop_call_io (io=0x55bae816d4e0) at ioloop.c:599 ioloop = 0x55bae8153990 t_id = 2 __FUNCTION__ = "io_loop_call_io" #16 0x00007fc5ef1bcd8e in io_loop_handler_run_internal (ioloop=ioloop at entry=0x55bae8153990) at ioloop-epoll.c:223 ctx = 0x55bae81554b0 list = 0x55bae8156f10 io = <optimized out> tv = {tv_sec = 1799, tv_usec = 998558} events_count = <optimized out> msecs = <optimized out> ret = <optimized out> i = 0 j = <optimized out> call = <optimized out> __FUNCTION__ = "io_loop_handler_run_internal" #17 0x00007fc5ef1bb7d6 in io_loop_handler_run (ioloop=ioloop at entry=0x55bae8153990) at ioloop.c:648 No locals. #18 0x00007fc5ef1bb988 in io_loop_run (ioloop=0x55bae8153990) at ioloop.c:623 __FUNCTION__ = "io_loop_run" #19 0x00007fc5ef141353 in master_service_run (service=0x55bae8153830, callback=<optimized out>) at master-service.c:666 No locals. #20 0x000055bae72a1139 in main (argc=<optimized out>, argv=<optimized out>) at main.c:491 set_roots = {0x55bae74cc760 <imap_setting_parser_info>, 0x55bae74cca20 <lda_setting_parser_info>, 0x0} login_set = {auth_socket_path = 0x55bae814b048 "\001", postlogin_socket_path = 0x0, postlogin_timeout_secs = 60, callback = 0x55bae72bc1b0 <login_client_connected>, failure_callback = 0x55bae72bbb00 <login_client_failed>, request_auth_token = 1} service_flags = <optimized out> storage_service_flags = <optimized out> username = 0x0 auth_socket_path = 0x55bae72c5097 "auth-master" c = <optimized out> Gr. Matthijs -------------- next part -------------- A non-text attachment was scrubbed... Name: signature.asc Type: application/pgp-signature Size: 833 bytes Desc: not available URL: <https://dovecot.org/pipermail/dovecot/attachments/20170927/62ba47d9/attachment.sig>