> On 15/09/2021 17:12 admin <ad...@nji9.de> wrote: > > > Hi, > > We run dovecot + postfix + pigeonhole. Last week we observed some > coredumps in dovecot's lmtp processes. For some emails, postfix mailq > reported: > > > lost connection with nji9.de[/var/spool/postfix/private/dovecot-lmtp] while > > sending end of data -- message may be sent more than once > > Indeed, some users received some emails multiple times. > > dovecot.log contained a lot of related lines, all of them looking like this: > > > Sep 14 22:20:32 lmtp(u...@example.com)<16323><abcdef:24>: Info: sieve: > > Execution of script /home/vmail/example.com/user/.dovecot.sieve failed, but > > implicit keep was successful (user logfile > > /home/vmail/example.com/user/.dovecot.sieve.log may reveal additional > > details) > > Sep 14 22:20:32 lmtp(16323): Panic: file mail-user.c: line 229 > > (mail_user_deinit): assertion failed: ((*user)->refcount == 1) > > Sep 14 22:20:32 lmtp(16323): Error: Raw backtrace: > > /usr/lib/dovecot/libdovecot.so.0(backtrace_append+0x43) [0x68ac383e6073] -> > > /usr/lib/dovecot/libdovecot.so.0(backtrace_get+0x20) [0x68ac383e6190] -> > > /usr/lib/dovecot/libdovecot.so.0(+0xfaf1f) [0x68ac383f2f1f] -> > > /usr/lib/dovecot/libdovecot.so.0(+0xfafb1) [0x68ac383f2fb1] -> > > /usr/lib/dovecot/libdovecot.so.0(+0x4cd20) [0x68ac38344d20] -> > > /usr/lib/dovecot/libdovecot-storage.so.0(+0x38bbc) [0x68ac384f6bbc] -> > > dovecot/lmtp(lmtp_local_data+0x400) [0xfb684d63190] -> > > dovecot/lmtp(client_default_cmd_data+0x19d) [0xfb684d61c5d] -> > > dovecot/lmtp(cmd_data_continue+0x191) [0xfb684d619e1] -> > > /usr/lib/dovecot/libdovecot.so.0(+0x6cb09) [0x68ac38364b09] -> > > /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x6b) [0x68ac38408ebb] -> > > /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x13b) > > [0x68ac3840a5cb] -> > > /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x51) [0x68ac38408f61] > > -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x41) [0 x68ac38409131] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x14) [0x68ac3837af74] -> dovecot/lmtp(main+0x235) [0xfb684d60615] -> /usr/lib/libc.so.6(__libc_start_main+0xd5) [0x68ac3814ab25] -> dovecot/lmtp(_start+0x2e) [0xfb684d6072e] > > Sep 14 22:20:33 lmtp(16323): Fatal: master: service(lmtp): child 16323 > > killed with signal 6 (core dumped) > > Equally frequent, journalctl said: > > > Sep 14 22:20:33 nji9.de systemd-coredump[16358]: Process 16323 (lmtp) of > > user 0 dumped core. > > Found module linux-vdso.so.1 with build-id: > > 7b6fd2add8450c7af3684522368e4ce83f762f41 > > Found module libgcc_s.so.1 with build-id: > > 7f8508bb914546ada778809b64b99d234337d835 > > Found module libffi.so.7 with build-id: > > de60e99f39569d11d09160bbdcd486cedc87d2b6 > > Found module libp11-kit.so.0 with build-id: > > 5314ec746546ada6f442b6fdfae15eab9f6d3cdc > > Found module libcrypt.so.2 with build-id: > > 3743451bdaf36f951f926927633fd964813025d0 > > Found module librt.so.1 with build-id: > > 75484da2d6f1515189eefa076e0a40328834cd16 > > Found module libnss_systemd.so.2 with build-id: > > 22990ff716d182c427e26b7a3cf94048b55b3e75 > > Found module libnss_files.so.2 with build-id: > > 1a36dfc01d3a1010b2ee79766a24a8090a3266d5 > > Found module libdovecot-sieve.so.0 with build-id: > > 8f87ae1b5f982453421532a7ac0f309813add7ce > > Found module lib90_sieve_plugin.so with build-id: > > 4cd814cc28d0259b7f837b3b8583adabbf608d6a > > Found module lib10_quota_plugin.so with build-id: > > a63664ff7754f0c234344a89f2d28aa3f6650929 > > Found module libpthread.so.0 with build-id: > > 07c8f95b4f3251d08550217ad8a1f31066229996 > > Found module libcrypto.so.1.1 with build-id: > > 6d23f0a3f354825868d044684fad31d482cc9210 > > Found module libssl.so.1.1 with build-id: > > 959cd8f1dd43fc31aeb93caac4eda87c907ef18b > > Found module libssl_iostream_openssl.so with build-id: > > 7cde2343f52a797e4fe77de7d0e7c1cb4983706b > > Found module ld-linux-x86-64.so.2 with build-id: > > 040cc3dd10461562f177df39e3be2f3704258c3c > > Found module libdl.so.2 with build-id: > > 5abc547e7b0949f89f3c0e21ab0c8331a7440a8a > > Found module libc.so.6 with build-id: > > 4b406737057708c0e4c642345a703c47a61c73dc > > Found module libdovecot.so.0 with build-id: > > e2c3dc8d5ee8012c83dc2a5f220de42e020857dc > > Found module libdovecot-storage.so.0 with build-id: > > 1c80627fdc89752d8dc749ecfefae1e31445bb67 > > Found module libdovecot-lda.so.0 with build-id: > > 826670da875938b71bd20af87dab4eb2cbbfef61 > > Found module lmtp with build-id: 1f51ab7200356943590ecee21d298c808833d4e2 > > Stack trace of thread 16323: > > #0 0x000068ac3815fd22 raise (libc.so.6 + 0x3cd22) > > #1 0x000068ac38149862 abort (libc.so.6 + 0x26862) > > #2 0x000068ac38345084 n/a (libdovecot.so.0 + 0x4d084) > > #3 0x000068ac383f2fb1 n/a (libdovecot.so.0 + 0xfafb1) > > #4 0x000068ac38344d20 i_panic (libdovecot.so.0 + 0x4cd20) > > #5 0x000068ac384f6bbc n/a (libdovecot-storage.so.0 + 0x38bbc) > > #6 0x00000fb684d63190 lmtp_local_data (lmtp + 0x9190) > > #7 0x00000fb684d61c5d client_default_cmd_data (lmtp + 0x7c5d) > > #8 0x00000fb684d619e1 cmd_data_continue (lmtp + 0x79e1) > > #9 0x000068ac38364b09 n/a (libdovecot.so.0 + 0x6cb09) > > #10 0x000068ac38408ebb io_loop_call_io (libdovecot.so.0 + 0x110ebb) > > #11 0x000068ac3840a5cb io_loop_handler_run_internal (libdovecot.so.0 + > > 0x1125cb) > > #12 0x000068ac38408f61 io_loop_handler_run (libdovecot.so.0 + 0x110f61) > > #13 0x000068ac38409131 io_loop_run (libdovecot.so.0 + 0x111131) > > #14 0x000068ac3837af74 master_service_run (libdovecot.so.0 + 0x82f74) > > #15 0x00000fb684d60615 main (lmtp + 0x6615) > > #16 0x000068ac3814ab25 __libc_start_main (libc.so.6 + 0x27b25) > > #17 0x00000fb684d6072e _start (lmtp + 0x672e) > > Sep 14 22:20:33 nji9.de systemd[1]: systemd-coredump@32-16357-0.service: > > Deactivated successfully. > > > The sieve logfile, which was mentioned in dovecot.log, contains: > > > sieve: info: started log at 2021-09-14 22:20:32 +0200. > > error: msgid=<abcdef...@example.com>: fileinto action: failed to store into > > mailbox 'INBOX.MyFolder': Mailbox doesn't exist: INBOX.MyFolder. > > After removing all failed sieve rules which appeared in the logs, the > mail queue was processed without errors. There were no core dumps any more. > > The strange thing is that there are some failing sieve rules left. The > sieve log of one user still contains errors. But there are no coredumps > any more. > > > sieve: info: started log at 2021-09-14 23:30:31 +0200. > > error: msgid=<abcdef...@example.com>: fileinto action: failed to store into > > mailbox 'INBOX.OtherFolder': Mailbox doesn't exist: INBOX.OtherFolder. > > Dovecot version: 2.3.16 > Operating system or Linux distribution name: Arch Linux > CPU architecture: x86_64 > Filesystem: ext4 > Kernel: Linux nji9.de 5.13.16-hardened1-1-hardened #1 SMP PREEMPT Sun, > 12 Sep 2021 20:28:26 +0000 x86_64 GNU/Linux > > I found a possibly related change (same error message as in the logs) in > the dovecot changelog: > > > 2021-08-18 19:49:43 +0200 Timo Sirainen <timo.sirai...@open-xchange.com> > > (b401e41) > > > > imap: Fix mailbox leak if MOVE can't open the source mailbox > > > > Broken by 143b7c2b412ed8f155e812603fda81886bec466e > > > > Fixes: Panic: file mail-user.c: line 229 (mail_user_deinit): assertion > > failed: ((*user)->refcount == 1) > > > > M src/imap/cmd-copy.c > > I don't know if that change fixes the issue. Note that there is no new > dovecot release yet. > > Trying to reproduce the error would be hard because this is a production > system. We have coredumps, but as they might contain sensitive > information, we'd prefer to not send them over a public mailing list. > > Do you have any clue on this issue? > > Best regards, > > the nji9.de crew
Hi! This is most likely fixed with https://github.com/dovecot/pigeonhole/compare/9f3002393fe1c1fe317121d03591569dac120739%5E..4596d39908a868783fae9a0c2fd264409c0aaa96.patch Aki