Panic: file ostream.c: assertion failed when using mail_filter on RHEL8

23 Apr 2021


      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.1

lport=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}SF5
hEeUZVO4ydasqNb040KHWGyin791L40BYR8cXf+I0EGeetzq5Cg==","userdb_password
":"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,<i7avXaHAuL
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        603cbf25103fc9a6
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.com

quota_rule=*:bytes=1073741824        password=<hidden>

home=/var/vmail/test=40example.com@ciphermail.private        auth_mech=
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)

Martijn Brinkers (list)

Martijn Brinkers (list)

tags

participants (1)