The same problem occurs when running 2.3.13 on RHEL8
Is this a RHEL8 specific issue?
Log output
Apr 24 14:14:38 webmail dovecot[568870]: master: Dovecot v2.3.13 (89f716dc2) starting up for imap Apr 24 14:15:13 webmail dovecot[568872]: imap-login: Login: user=< test=40example.com@ciphermail.private>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=584990, secured, session=<XCWDirjAZIJ/AAAB> Apr 24 14:15:13 webmail dovecot[568872]: imap( test=40example.com@ciphermail.private)<584990><XCWDirjAZIJ/AAAB>: Logged out in=44 out=617 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0 Apr 24 14:15:20 webmail dovecot[568872]: imap-login: Login: user=< test=40example.com@ciphermail.private>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=589277, secured, session=<6ebjirjAbIJ/AAAB> Apr 24 14:15:20 webmail dovecot[568872]: imap( test=40example.com@ciphermail.private)<589277><6ebjirjAbIJ/AAAB>: Panic: file ostream.c: line 204 (o_stream_flush): assertion failed: (stream->stream_errno != 0) Apr 24 14:15:20 webmail dovecot[568872]: imap( test=40example.com@ciphermail.private)<589277><6ebjirjAbIJ/AAAB>: Error: Raw backtrace: /usr/lib64/dovecot/libdovecot.so.0(backtrace_append+0x41) [0x7fc62f5b7d41] -> /usr/lib64/dovecot/libdovecot.so.0(backtrace_get+0x22) [0x7fc62f5b7e62] -> /usr/lib64/dovecot/libdovecot.so.0(+0x1041eb) [0x7fc62f5c41eb] -> /usr/lib64/dovecot/libdovecot.so.0(+0x104287) [0x7fc62f5c4287] -> /usr/lib64/dovecot/libdovecot.so.0(+0x5a50b) [0x7fc62f51a50b] -> /usr/lib64/dovecot/libdovecot.so.0(+0x5eb38) [0x7fc62f51eb38] -> /usr/lib64/dovecot/libdovecot-storage.so.0(maildir_save_finish+0x9a) [0x7fc62f91614a] -> /usr/lib64/dovecot/lib10_quota_plugin.so(+0x10658) [0x7fc62eaea658] -> /usr/lib64/dovecot/libdovecot- storage.so.0(mailbox_save_finish+0x77) [0x7fc62f8ee2b7] -> dovecot/imap(+0x1350d) [0x56192db1350d] -> dovecot/imap(+0x13baf) [0x56192db13baf] -> dovecot/imap(cmd_append+0x12c) [0x56192db13e0c] -> dovecot/imap(command_exec+0x6c) [0x56192db2261c] -> dovecot/imap(+0x206af) [0x56192db206af] -> dovecot/imap(+0x20761) [0x56192db20761] -> dovecot/imap(client_handle_input+0x1c5) [0x56192db20b45] -> dovecot/imap(client_input+0x76) [0x56192db21046] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_call_io+0x6d) [0x7fc62f5da75d] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x139) [0x7fc62f5dbd79] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run+0x50) [0x7fc62f5da800] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x48) [0x7fc62f5da978] -> /usr/lib64/dovecot/libdovecot.so.0(master_service_run+0x17) [0x7fc62f54ec67] -> dovecot/imap(main+0x335) [0x56192db126c5] -> /lib64/libc.so.6(__libc_start_main+0xf3) [0x7fc62f120803] -> dovecot/imap(_start+0x2e) [0x56192db1287e] Apr 24 14:15:20 webmail dovecot[568872]: imap(test=40example.com@ciphermail.private)<589277><6ebjirjAbIJ/AAAB>: Fatal: master: service(imap): child 589277 killed with signal 6 (core not dumped - https://dovecot.org/bugreport.html#coredumps - set /proc/sys/fs/suid_dumpable to 2) On Fri, 2021-04-23 at 12:38 +0200, Martijn Brinkers (list) wrote:
Hi,
I installed dovecot on a new up-to-date RHEL8 test system and configured a simple mail_filter plugin which only copies the input back to the output (i.e., the filter does nothing special).
On RHEL8 I get the following panic when saving the mail. The Dovecot version that comes with RHEL8 is dovecot-2.3.8-4.el8.x86_64
The mail_filter works correctly on an Ubuntu machine )2.2.33.2- 1ubuntu4.7)
Any idea what's causing this panic on RHEL8 and how to fix it?
Kind regards,
Martijn Brinkers
Log output (panic log is at the bottom)
Apr 23 10:35:54 ciphermail-webmail dovecot[18680]: master: Dovecot v2.3.8 (9df20d2db) starting up for imap Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: auth client connected (pid=19771) Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: client in: AUTH 1 PLAIN service=imap secured
se ssion=i7avXaHAuLh/AAAB lip=127.0.0.1 rip=127.0.0.1lport=143 rport=47288 resp=<hidden> Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: dict( test@example.com,127.0.0.1,<i7avXaHAuLh/AAAB>): Performing passdb lookup Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth- worker(19774): Debug: Loading modules from directory: /usr/lib64/dovecot/auth Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth- worker(19774): Debug: Module loaded: /usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth- worker(19774): Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth- worker(19774): Debug: conn unix:auth-worker (pid=19773,uid=97): Server accepted connection (fd=13) Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth- worker(19774): Debug: conn unix:auth-worker (pid=19773,uid=97): Sending version handshake Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth- worker(19774): Debug: conn unix:auth-worker (pid=19773,uid=97): auth-worker<1>: Handling PASSV request Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth- worker(19774): Debug: dict(test@example.com,127.0.0.1,<i7avXaHAuLh/AAAB>): Performing passdb lookup Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth- worker(19774): Debug: dict(test@example.com,127.0.0.1,<i7avXaHAuLh/AAAB>): Lookup: shared/passdb/test@example.com/test = {"userdb_email":" test@example.com ","userdb_quota_rule":"*:bytes=1073741824","password":"{SSHA256.b64}S F5 hEeUZVO4ydasqNb040KHWGyin791L40BYR8cXf+I0EGeetzq5Cg==","userdb_passwo rd ":"test","userdb_home":" /var/vmail/test=40example.com@ciphermail.private","user":" test=40example.com@ciphermail.private"} Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth- worker(19774): Debug: dict(test@example.com,127.0.0.1,<i7avXaHAuLh/AAAB>): username changed test@example.com -> test=40example.com@ciphermail.private Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth- worker(19774): Debug: dict(test=40example.com@ciphermail.private,127.0.0.1,<i7avXaHA uL h/AAAB>): Finished passdb lookup Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth- worker(19774): Debug: conn unix:auth-worker (pid=19773,uid=97): auth-worker<1>: Finished Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: dict( test@example.com,127.0.0.1,<i7avXaHAuLh/AAAB>): username changed test@example.com -> test=40example.com@ciphermail.private Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: dict( test=40example.com@ciphermail.private,127.0.0.1,<i7avXaHAuLh/AAAB>): Finished passdb lookup Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: auth( test=40example.com@ciphermail.private,127.0.0.1,<i7avXaHAuLh/AAAB>): Auth request finished Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: client passdb out: OK 1
user=test=40example.com@ciphermail.private
original_user=test@example.com Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: master in: REQUEST 3373400065 19771 1 603cbf25103fc9 a6 77ceabe45f077e40 session_pid=19776 request_auth_token Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: prefetch(test=40example.com@ciphermail.private,127.0.0.1,<i7avXaHAuLh /A AAB>): Performing userdb lookup Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: prefetch(test=40example.com@ciphermail.private,127.0.0.1,<i7avXaHAuLh /A AAB>): success Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: prefetch(test=40example.com@ciphermail.private,127.0.0.1,<i7avXaHAuLh /A AAB>): Finished userdb lookup Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: master userdb out: USER 3373400065
test=40example.com@ciphermail.private email=test@example.comquota_rule=*:bytes=1073741824 password=<hidden>home=/var/vmail/test=40example.com@ciphermail.private auth_mec h= PLAIN auth_token=819d2ad4117e4e4139991fab046e13304880e935
auth_user=test@example.com Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap-login: Login: user=<test=40example.com@ciphermail.private>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=19776, secured, session=<i7avXaHAuLh/AAAB> Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Loading modules from directory: /usr/lib64/dovecot Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Module loaded: /usr/lib64/dovecot/lib10_mail_filter_plugin.so Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Module loaded: /usr/lib64/dovecot/lib11_imap_quota_plugin.so Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Added userdb setting: plugin/auth_mech=PLAIN Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Added userdb setting: plugin/email=test@example.com Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Added userdb setting: plugin/password=<hidden> Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Added userdb setting: plugin/quota_rule=*:bytes=1073741824 Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Effective uid=986, gid=983, home=/var/vmail/test=40example.com@ciphermail.private Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: mail_filter: Filtering mail_filter via socket /var/run/dovecot/mail- filter Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: mail_filter: Filtering mail_filter_out via socket /var/run/dovecot/mail-filter-out Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Quota root: name=User quota backend=maildir args= Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Quota rule: root=User quota mailbox=* bytes=1073741824 messages=0 Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Quota rule: root=User quota mailbox=Trash bytes=+107374182 (10%) messages=0 Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Quota grace: root=User quota bytes=107374182 (10%) Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: maildir++: root=/var/vmail/test=40example.com@ciphermail.private, index=, indexpvt=, control=, inbox=/var/vmail/test=40example.com@ciphermail.private, alt= Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Debug: Mailbox Drafts: Mailbox opened because: APPEND Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Panic: file ostream.c: line 201 (o_stream_flush): assertion failed: (stream-
stream_errno != 0)
Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap( test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Error: Raw backtrace: /usr/lib64/dovecot/libdovecot.so.0(+0xf895b) [0x7f8f1d3d995b] -> /usr/lib64/dovecot/libdovecot.so.0(+0xf89f7) [0x7f8f1d3d99f7] -> /usr/lib64/dovecot/libdovecot.so.0(+0x55b05) [0x7f8f1d336b05] -> /usr/lib64/dovecot/libdovecot.so.0(+0x5a1bd) [0x7f8f1d33b1bd] -> /usr/lib64/dovecot/libdovecot- storage.so.0(maildir_save_finish+0x99) [0x7f8f1d723fa9] -> /usr/lib64/dovecot/lib10_quota_plugin.so(+0xfcee) [0x7f8f1bd5acee] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mailbox_save_finish+0x7d) [0x7f8f1d6fafdd] -> dovecot/imap(+0x132fd) [0x564a032332fd] -> dovecot/imap(command_exec+0x78) [0x564a03241cd8] -> dovecot/imap(+0x128ad) [0x564a032328ad] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_call_io+0x73) [0x7f8f1d3f10c3] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x135 ) [0x7f8f1d3f2775] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run+0x50) [0x7f8f1d3f1170] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x48) [0x7f8f1d3f12d8] -> /usr/lib64/dovecot/libdovecot.so.0(master_service_run+0x17) [0x7f8f1d368eb7] -> dovecot/imap(main+0x335) [0x564a03232445] -> /lib64/libc.so.6(__libc_start_main+0xf3) [0x7f8f1ca5b803] -> dovecot/imap(_start+0x2e) [0x564a032325fe] Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap(test=40example.com@ciphermail.private)<19776><i7avXaHAuLh/AAAB>: Fatal: master: service(imap): child 19776 killed with signal 6 (core not dumped - https://dovecot.org/bugreport.html#coredumps - set /proc/sys/fs/suid_dumpable to 2)