Panic: file ostream.c: assertion failed when using mail_filter on RHEL8
Martijn Brinkers (list)
martijn.list at gmail.com
Sat Apr 24 17:18:26 EEST 2021
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 at 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 at 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 at 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 at 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 at 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 at 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.1
>
> lport=143 rport=47288 resp=<hidden>
> Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: dict(
> test at 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 at 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 at example.com,127.0.0.1,<i7avXaHAuLh/AAAB>): Lookup:
> shared/passdb/test at example.com/test = {"userdb_email":"
> test at 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 at ciphermail.private","user":"
> test=40example.com at ciphermail.private"}
> Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth-
> worker(19774):
> Debug: dict(test at example.com,127.0.0.1,<i7avXaHAuLh/AAAB>): username
> changed test at example.com -> test=40example.com at ciphermail.private
> Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth-
> worker(19774):
> Debug: dict(test=40example.com at 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 at example.com,127.0.0.1,<i7avXaHAuLh/AAAB>): username changed
> test at example.com -> test=40example.com at ciphermail.private
> Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: auth: Debug: dict(
> test=40example.com at 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 at 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 at ciphermail.private
> original_user=test at 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 at 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 at 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 at 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 at ciphermail.private email=test at example.com
>
> quota_rule=*:bytes=1073741824 password=<hidden>
> home=/var/vmail/test=40example.com at ciphermail.private auth_mec
> h=
> PLAIN auth_token=819d2ad4117e4e4139991fab046e13304880e935
>
> auth_user=test at example.com
> Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap-login: Login:
> user=<test=40example.com at 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 at 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 at 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 at 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 at 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 at 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 at ciphermail.private)<19776><i7avXaHAuLh/AAAB>:
> Debug:
> Added userdb setting: plugin/email=test at example.com
> Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap(
> test=40example.com at 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 at 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 at ciphermail.private)<19776><i7avXaHAuLh/AAAB>:
> Debug:
> Effective uid=986, gid=983,
> home=/var/vmail/test=40example.com at ciphermail.private
> Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap(
> test=40example.com at 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 at 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 at 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 at 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 at 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 at 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 at ciphermail.private)<19776><i7avXaHAuLh/AAAB>:
> Debug:
> maildir++: root=/var/vmail/test=40example.com at ciphermail.private,
> index=, indexpvt=, control=,
> inbox=/var/vmail/test=40example.com at ciphermail.private, alt=
> Apr 23 10:36:17 ciphermail-webmail dovecot[18682]: imap(
> test=40example.com at 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 at 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 at 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 at 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 at 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)
>
>
>
More information about the dovecot
mailing list