dovecot crash with Panic: file istream-header-filter.c: line 663

[Patrick Mansfield]

On Mon, Mar 13, 2023 at 11:01:35AM +0200, Timo Sirainen wrote:
> On 12. Mar 2023, at 20.17, Patrick Mansfield <patmans at yahoo.com> wrote:
> > 
> > Mar 12 10:32:27 goffin dovecot[8269]: imap(patman)<8452><r+ynYLf2PrDAqAEE>: Panic: file istream-header-filter.c: line 663 (i_stream_header_filter_snapshot_free): assertion failed: (snapshot->mstream->snapshot_pending)
> 
> This is unfortunately rather difficult to debug. First you should find out which folder and mail this is happening in. You can do that with gdb:
> 
> > #16 0x00007fa3849aa60a in index_mail_parse_headers_internal (mail=mail at entry=0x56150ea5fc78, headers=headers at entry=0x0) at index/index-mail-headers.c:465
> 
> fr 16
> p mail.box.vname
> p mail.uid

OK, I had to use a bit different syntax:

(gdb) fr 16
#16 0x00007fa3849aa60a in index_mail_parse_headers_internal (mail=mail at entry=0x56150ea5fc78, headers=headers at entry=0x0)
    at index/index-mail-headers.c:465
465                     message_parser_parse_header(data->parser_ctx, &data->hdr_size,
(gdb) p mail->mail.mail->box->vname
$1 = 0x56150ea60840 "INBOX"
(gdb)  p mail->mail.mail->uid
$2 = 33655

> Likely deleting that mail manually from the mbox will fix it. Of course, it would be nice if we were able to reproduce the bug also. Once you've found the broken folder, could you anonymize the mbox file contents and send it to me privately? https://github.com/dovecot/tools/blob/main/mbox-anonymize.pl can help you do it. Although I'm not sure if even that is enough to reproduce the bug - might need the dovecot.index* files also but those contain cached headers from the emails, which can be rather sensitive data.
> 
> Other things besides deleting the mail that might help, and would be useful to know whether they help:
> 
>  * doveadm fetch -u user imap.bodystructure mailbox $folder uid $uid

The above hits the same crash:

$ doveadm fetch -u patman imap.bodystructure mailbox INBOX uid 33655
Error: net_connect_unix(/run/dovecot/stats-writer) failed: Permission denied
doveadm(patman): Panic: file istream-header-filter.c: line 663 (i_stream_header_filter_snapshot_free): assertion failed: (snapshot->mstream->snapshot_pending)
doveadm(patman): Error: Raw backtrace: /usr/lib64/dovecot/libdovecot.so.0(backtrace_append+0x46) [0x7fd12d418f46] -> /usr/lib64/dovecot/libdovecot.so.0(backtrace_get+0x22) [0x7fd12d419082] -> /usr/lib64/dovecot/libdovecot.so.0(+0x109557) [0x7fd12d423557] -> /usr/lib64/dovecot/libdovecot.so.0(+0x109597) [0x7fd12d423597] -> /usr/lib64/dovecot/libdovecot.so.0(+0x5e0e1) [0x7fd12d3780e1] -> /usr/lib64/dovecot/libdovecot.so.0(+0x59df8) [0x7fd12d373df8] -> /usr/lib64/dovecot/libdovecot.so.0(i_stream_snapshot_free+0x1c) [0x7fd12d430b6c] -> /usr/lib64/dovecot/libdovecot.so.0(i_stream_unref+0x54) [0x7fd12d430c14] -> /usr/lib64/dovecot/libdovecot.so.0(message_parse_header_deinit+0x19) [0x7fd12d401179] -> /usr/lib64/dovecot/libdovecot.so.0(+0xe8ea1) [0x7fd12d402ea1] -> /usr/lib64/dovecot/libdovecot.so.0(message_parser_parse_next_block+0x4c) [0x7fd12d403edc] -> /usr/lib64/dovecot/libdovecot.so.0(message_parser_parse_header+0x59) [0x7fd12d404029] -> /usr/lib64/dovecot/libdovecot-storage.so.0(index_mail_parse_headers_internal+0x11a) [0x7fd12d5ce60a] -> /usr/lib64/dovecot/libdovecot-storage.so.0(index_mail_parse_headers+0x4e) [0x7fd12d5ce71e] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0xdd21e) [0x7fd12d5d421e] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0xdd2b3) [0x7fd12d5d42b3] -> /usr/lib64/dovecot/libdovecot-storage.so.0(index_mail_get_special+0x20d) [0x7fd12d5d46cd] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_get_special+0xe) [0x7fd12d553a1e] -> /usr/bin/doveadm(+0x3893c) [0x5650816db93c] -> /usr/bin/doveadm(+0x3e12e) [0x5650816e112e] -> /usr/bin/doveadm(+0x3bba1) [0x5650816deba1] -> /usr/bin/doveadm(doveadm_cmd_ver2_to_mail_cmd_wrapper+0x29b) [0x5650816dfe0b] -> /usr/bin/doveadm(doveadm_cmd_run_ver2+0x4ff) [0x5650816ea67f] -> /usr/bin/doveadm(doveadm_cmd_try_run_ver2+0x3b) [0x5650816ea6fb] -> /usr/bin/doveadm(main+0x282) [0x5650816cbd92] -> /lib64/libc.so.6(+0x27510) [0x7fd12cb6a510] -> /lib64/libc.so.6(__libc_start_main+0x89) [0x7fd12cb6a5c9] -> /usr/bin/doveadm(_start+0x25) [0x5650816cbfa5]
Aborted (core dumped)

>  * doveadm mailbox cache remove -u user mailbox $folder uid $uid

Ran (not as root):

$ doveadm mailbox cache remove -u patman mailbox INBOX uid 33655
Error: net_connect_unix(/run/dovecot/stats-writer) failed: Permission denied
mailbox uid   result
INBOX   33655 ok

After the above, it's no longer crashing, and my email client's "pending operations" have
cleared.

And this now works:

$ doveadm fetch -u patman imap.bodystructure mailbox INBOX uid 33655
Error: net_connect_unix(/run/dovecot/stats-writer) failed: Permission denied
imap.bodystructure: ("text" "plain" ("charset" "utf-8") NIL NIL "8bit" 5555 107 NIL NIL NIL NIL)("text" "html" ("charset" "utf-8") NIL NIL "8bit" 34300 270 NIL NIL NIL NIL) "alternative" ("boundary" "n1UvlD2eFkGX=_?:") NIL NIL NIL

I didn't get the anonimized mbox first, so I can't get any more details than what I have
in the existing core dump, but the above seems to imply the cache was the issue one way or
another.

Thanks!

-- Patrick