Hi, For a few weeks I've been running a custom notification script[1] that uses IMAP NOTIFY. The script uses a single connection, sets up a NOTIFY watch on a couple of mailboxes + automatic FETCH for the selected mailbox. If a status update arrives for a different mailbox, it selects that box and fetches the mail.
Today I got the following error in the log: > Aug 5 14:56:12 karif dovecot[1881]: imap(xxxx)<22699><TBjUXqtyZI5R2c0k>: > Panic: file mail.c: line 242 (mail_get_header_stream): assertion failed: > (headers->box == mail->box) > Aug 5 14:56:12 karif dovecot[1881]: imap(xxxx)<22699><TBjUXqtyZI5R2c0k>: > Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0xcfbff) > [0x7fda11806bff] -> /usr/lib/dovecot/libdovecot.so.0(+0xcfcba) > [0x7fda11806cba] -> /usr/lib/dovecot/libdovecot.so.0(+0x414bb) > [0x7fda117784bb] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0x3566e) > [0x7fda11aec66e] -> > /usr/lib/dovecot/libdovecot-storage.so.0(imap_msgpart_open+0x43b) > [0x7fda11bb3a1b] -> dovecot/imap(+0x211ed) [0x55e00d2a21ed] -> > dovecot/imap(+0x1f69c) [0x55e00d2a069c] -> > dovecot/imap(imap_fetch_more_no_lock_update+0xf) [0x55e00d2a17ff] -> > dovecot/imap(+0x23891) [0x55e00d2a4891] -> > dovecot/imap(imap_client_notify_newmails+0xfa) [0x55e00d2a4a6a] -> > dovecot/imap(imap_sync_more+0x755) [0x55e00d2a9f75] -> dovecot/imap(+0x29006) > [0x55e00d2aa006] -> dovecot/imap(cmd_sync_delayed+0x27b) [0x55e00d2aa50b] -> > /usr/lib/dovecot/libdovecot.so.0(io_loop_handle_timeouts+0x10d) > [0x7fda1181c82d] -> > /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0xd2) > [0x7fda1181df52] -> > /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x4d) [0x7fda1181caad] > -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x41) [0x7fda1181cc11] -> > /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x14) [0x7fda117a0074] -> > dovecot/imap(main+0x342) [0x55e00d28fb82] -> > /usr/lib/libc.so.6(__libc_start_main+0xeb) [0x7fda1139e06b] -> > dovecot/imap(_start+0x2a) [0x55e00d28fd1a] > Aug 5 14:56:12 karif dovecot[1881]: imap(xxxx)<22699><TBjUXqtyZI5R2c0k>: > Fatal: master: service(imap): child 22699 killed with signal 6 (core not > dumped - https://dovecot.org/bugreport.html#coredumps - set > /proc/sys/fs/suid_dumpable to 2) I'm not sure what happened exactly, but I can tell you that a new mail, that went to the selected mailbox (INBOX), was arriving at the time of the crash. The script logs the IMAP traffic (sadly without timestamps so far). Here's a slightly censored (3 dots in a few places) and stripped log in the hope that it helps. Lines prefixed with >> are sent to the server, those with << are received from the server. > [login stuff] > server-speed >> CMD-2 notify set (selected (MessageExpunge MessageNew (uid > body.peek[header.fields (from to subject)]))) (mailboxes (INBOX > INBOX.Postmaster ... ... ... ...) (MessageNew MessageExpunge MailboxName)) > server-speed << CMD-2 OK NOTIFY completed (0.002 + 0.000 + 0.001 secs). > [various untagged fetches/selects + fetch/noops] > [script was in a different mailbox, status update for INBOX arrives thus > script select INBOX] > server-speed >> CMD-51 select INBOX > server-speed << * OK [CLOSED] Previous mailbox closed. > server-speed << * FLAGS (\Answered \Flagged \Deleted \Seen \Draft $MDNSent > Junk redirected $label2 $label4 $label5 NonJunk $Forwarded $label3 $label1 > done Old) > server-speed << * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen > \Draft $MDNSent Junk redirected $label2 $label4 $label5 NonJunk $Forwarded > $label3 $label1 done Old \*)] Flags permitted. > server-speed << * 20 EXISTS > server-speed << * 1 RECENT > server-speed << * OK [UNSEEN 14] First unseen. > server-speed << * OK [UIDVALIDITY 1336752926] UIDs valid > server-speed << * OK [UIDNEXT 41885] Predicted next UID > server-speed << * OK [HIGHESTMODSEQ 138681] Highest > server-speed << CMD-51 OK [READ-WRITE] Select completed (0.001 + 0.000 > secs). > server-speed >> CMD-52 uid fetch 41884 (body.peek[header.fields (from to > subject)]) > server-speed << * 20 FETCH (UID 41884 BODY[HEADER.FIELDS (FROM TO SUBJECT)] > {164} > server-speed << From: ... > server-speed << To: ... > server-speed << Subject: ... > server-speed << > server-speed << ) > server-speed << CMD-52 OK Fetch completed (0.001 + 0.000 secs). > Got data for notification: [...] > Sending notification with data: {...} > [the next few lines happen over a span of roughly 9 minutes] > server-speed << * 20 EXPUNGE > server-speed << * 0 RECENT > server-speed << * 8 EXPUNGE > server-speed << * 11 EXPUNGE > server-speed << * 18 EXISTS > server-speed << * 1 RECENT > server-speed << * 18 FETCH (UID 41885 > [this is apparnently when the server crashed] I'm afraid I can't reproduce the issue and I don't have the time to try right now, so I can't provide much more information than what is in here. Still, if you have questions, feel free to ask me. Just know that I won't be getting you a better backtrace/coredump any time soon. [1] https://git.server-speed.net/users/flo/App-ImapNotify/tree/ Florian
signature.asc
Description: PGP signature