2.13 read, i_stream_read_memarea: assertion failed: (!stream->blocking)

Stuart Henderson stu at spacehopper.org
Thu Jan 28 14:45:04 EET 2021


On 2021-01-24, Stuart Henderson <stu at spacehopper.org> wrote:
> I'm seeing this on some mailboxes with 2.13 on OpenBSD amd64 (recent
> snapshot):
>
> dovecot: imap(sthen)<47220><ARy1oKS5lWDDX7sa>: Panic: file istream.c: line 332 (i_stream_read_memarea): assertion failed: (!stream->blocking)
>
> Using sieve, imapsieve, replicator, zlib (zlib_save = lz4 and has
> been for some time, so the relevant messages probably use this).
> Using mmap_disable because OpenBSD.
>
> Any suggestions how to handle it, preferably automatically?
> (even if a message is corrupt/lost it would be really nice if a
> standard client could still access the mailbox rather than kill
> the imap process while reading headers).

Thought I'd try doveadm force-resync ("For sdbox and mdbox mailboxes the
storage files will be also checked") but this doesn't help.

Getting some ideas for the seemingly related thread about zstd/xz
https://dovecot.org/pipermail/dovecot/2020-September/119890.html I've had
a play with doveadm fetch.

Doing 'doveadm fetch -u sthen "uid text" mailbox ports | grep ^uid | tail'
I find various messages from around June/July 2020 that trigger the crash.
Expunging the last displayed uid at that point I get further but I run into
more after a few messages. I don't mind doing that with this mailbox to
get things working but if it can be used to provide/test something more
robust that would be better.

Using "doveadm -o mail_plugins=virtual fetch" I see that they're definitely
lz4 compressed.

Seems odd but if I do text fetches by uid I don't run into any failure?

$ for i in `cat /tmp/uid.p|cut -d: -f2`;do doveadm fetch -u sthen text mailbox ports uid $i > /dev/null || echo $i;done
[no output]

Any ideas?



> bt first for ease of reading, followed by bt full in case it has any
> additional clues.
>
> (gdb) bt
> #0  thrkill () at /tmp/-:3
> #1  0x00000e9158c7c3ae in _libc_abort () at /usr/src/lib/libc/stdlib/abort.c:51
> #2  0x00000e91adc00c26 in default_fatal_finish (type=LOG_TYPE_PANIC, status=0) at failures.c:459
> #3  0x00000e91adbff034 in fatal_handler_real (ctx=0x7f7ffffcdd90, format=<optimized out>,
>     args=<optimized out>) at failures.c:471
> #4  0x00000e91adbfffb1 in i_internal_fatal_handler (ctx=0x0,
>     format=0x6 <error: Cannot access memory at address 0x6>, args=0x0) at failures.c:866
> #5  0x00000e91adbff266 in i_panic (format=0x6 <error: Cannot access memory at address 0x6>)
>     at failures.c:523
> #6  0x00000e91adc0f15c in i_stream_read_memarea (stream=0xe917ead3480) at istream.c:332
> #7  0x00000e91adc1925f in read_more (sstream=0xe91431c4800) at istream-seekable.c:149
> #8  0x00000e91adc19090 in read_from_buffer (sstream=0xe91431c4800, ret_r=0x7f7ffffcded8)
>     at istream-seekable.c:204
> #9  0x00000e91adc1856d in i_stream_seekable_read (stream=0xe91431c4800) at istream-seekable.c:265
> #10 0x00000e91adc0f0a4 in i_stream_read_memarea (stream=0xe91431c4880) at istream.c:313
> #11 0x00000e91adc16bbc in i_stream_limit_read (stream=0xe91e9ccca00) at istream-limit.c:49
> #12 0x00000e91adc0f0a4 in i_stream_read_memarea (stream=0xe91e9ccca80) at istream.c:313
> #13 0x00000e91adc0f79c in i_stream_read_copy_from_parent (istream=<optimized out>) at istream.c:387
> #14 0x00000e918e9729fa in i_stream_mail_read (stream=0xe91e9ccc000) at istream-mail.c:115
> #15 0x00000e91adc0f0a4 in i_stream_read_memarea (stream=0xe91e9ccc080) at istream.c:313
> #16 0x00000e91adc104f5 in i_stream_read (stream=0xe91e9ccc080) at istream.c:271
> #17 i_stream_read_data (stream=0xe91e9ccc080, data_r=0x7f7ffffce110, size_r=0x7f7ffffce100, threshold=1)
>     at istream.c:747
> #18 0x00000e91adbd6a18 in i_stream_read_bytes (stream=0x0, data_r=<optimized out>,
>     size_r=<optimized out>, wanted=<optimized out>) at ../../src/lib/istream.h:214
> #19 message_parse_header_next (ctx=0xe9183e1b180, hdr_r=0x7f7ffffce1d0) at message-header-parser.c:85
> #20 0x00000e91adbceef2 in read_header (mstream=0xe91e9cc6000) at istream-header-filter.c:195
> #21 i_stream_header_filter_read (stream=0xe91e9cc6000) at istream-header-filter.c:450
> #22 0x00000e91adc0f0a4 in i_stream_read_memarea (stream=0xe91e9cc6080) at istream.c:313
> #23 0x00000e91adc104f5 in i_stream_read (stream=0xe91e9cc6080) at istream.c:271
> #24 i_stream_read_data (stream=0xe91e9cc6080, data_r=0x7f7ffffce2c0, size_r=0x7f7ffffce2c8, threshold=0)
>     at istream.c:747
> #25 0x00000e91adbdc07b in i_stream_read_bytes (stream=0xe91e9cc6080, data_r=<optimized out>,
>     size_r=<optimized out>, wanted=<error reading variable: Cannot access memory at address 0x1>)
>     at ../../src/lib/istream.h:214
> #26 message_get_header_size (input=0xe91e9cc6080, hdr=0x7f7ffffce328, has_nuls_r=0x7f7ffffce3b7)
>     at message-size.c:19
> #27 0x00000e8f25e767d9 in imap_msgpart_get_partial_header (mail=0xe91e9cc4848,
>     mail_input=<optimized out>, msgpart=0xe91c92a2048, virtual_size_r=<optimized out>,
>     result_r=0x7f7ffffce408, have_crlfs_r=<optimized out>) at imap-msgpart.c:401
> #28 imap_msgpart_open_normal (mail=<optimized out>, msgpart=0xe91c92a2048, part=<optimized out>,
>     virtual_size_r=<optimized out>, result_r=0x7f7ffffce408, have_crlfs_r=<optimized out>)
>     at imap-msgpart.c:637
> #29 imap_msgpart_open (mail=<optimized out>, msgpart=0xe91c92a2048, result_r=0x7f7ffffce408)
>     at imap-msgpart.c:706
> #30 0x00000e8f25e672ff in fetch_body_msgpart (ctx=0xe9159845368, mail=<optimized out>,
>     body=0xe91e9cb4398) at imap-fetch-body.c:184
> #31 0x00000e8f25e65837 in imap_fetch_more_int (ctx=0xe9159845368, cancel=false) at imap-fetch.c:562
> #32 0x00000e8f25e6552c in imap_fetch_more (ctx=0xe9159845368, cmd=0xe9159845048) at imap-fetch.c:617
> #33 0x00000e8f25e55521 in cmd_fetch (cmd=0xe9159845048) at cmd-fetch.c:337
> #34 0x00000e8f25e62d12 in command_exec (cmd=0xe9159845048) at imap-commands.c:201
> #35 0x00000e8f25e61576 in client_command_input (cmd=0xe9159845048) at imap-client.c:1204
> #36 0x00000e8f25e61682 in client_command_input (cmd=0xe9159845048) at imap-client.c:1269
> #37 0x00000e8f25e5ffb4 in client_handle_next_command (client=0xe9159845848, remove_io_r=<optimized out>)
>     at imap-client.c:1313
> #38 client_handle_input (client=0xe9159845848) at imap-client.c:1327
> #39 0x00000e8f25e5e755 in client_input (client=0xe9159845848) at imap-client.c:1371
> #40 0x00000e91adc1c851 in io_loop_call_io (io=0xe91eb5d0b00) at ioloop.c:714
> #41 0x00000e91adc1f84c in io_loop_handler_run_internal (ioloop=0xe9162373d00) at ioloop-kqueue.c:164
> #42 0x00000e91adc1cfd9 in io_loop_handler_run (ioloop=0xe9162373d00) at ioloop.c:766
> #43 0x00000e91adc1cce8 in io_loop_run (ioloop=0xe9162373d00) at ioloop.c:739
> #44 0x00000e91adb77655 in master_service_run (service=0xe9193c39600, callback=0x6)
>     at master-service.c:853
> #45 0x00000e8f25e70dd1 in main (argc=1, argv=<optimized out>) at main.c:532
>
> (gdb) bt full
> #0  thrkill () at /tmp/-:3
> No locals.
> #1  0x00000e9158c7c3ae in _libc_abort () at /usr/src/lib/libc/stdlib/abort.c:51
>         sa = {
>           __sigaction_u = {
>             __sa_handler = 0x0,
>             __sa_sigaction = 0x0
>           },
>           sa_mask = 4294967295,
>           sa_flags = 0
>         }
>         mask = 4294967263
> #2  0x00000e91adc00c26 in default_fatal_finish (type=LOG_TYPE_PANIC, status=0) at failures.c:459
>         recursed = 0
>         backtrace = <optimized out>
> #3  0x00000e91adbff034 in fatal_handler_real (ctx=0x7f7ffffcdd90, format=<optimized out>,
>     args=<optimized out>) at failures.c:471
>         status = 6
> #4  0x00000e91adbfffb1 in i_internal_fatal_handler (ctx=0x0,
>     format=0x6 <error: Cannot access memory at address 0x6>, args=0x0) at failures.c:866
> No locals.
> #5  0x00000e91adbff266 in i_panic (format=0x6 <error: Cannot access memory at address 0x6>)
>     at failures.c:523
>         ctx = {
>           type = LOG_TYPE_PANIC,
>           exit_status = 0,
>           timestamp = 0x0,
>           timestamp_usecs = 0,
>           log_prefix = 0x0,
>           log_prefix_type_pos = 0
>         }
>         args = {{
>             gp_offset = 40,
>             fp_offset = 48,
>             overflow_arg_area = 0x7f7ffffcddf0,
>             reg_save_area = 0x7f7ffffcdce0
>           }}
> #6  0x00000e91adc0f15c in i_stream_read_memarea (stream=0xe917ead3480) at istream.c:332
>         _stream = 0xe917ead3400
>         old_size = 0
>         ret = 0
> #7  0x00000e91adc1925f in read_more (sstream=0xe91431c4800) at istream-seekable.c:149
>         ret = <optimized out>
>         size = <optimized out>
> #8  0x00000e91adc19090 in read_from_buffer (sstream=0xe91431c4800, ret_r=0x7f7ffffcded8)
>     at istream-seekable.c:204
>         old_skip = <optimized out>
>         stream = 0xe91431c4800
>         size = <optimized out>
>         data = <optimized out>
>         avail_size = <optimized out>
> #9  0x00000e91adc1856d in i_stream_seekable_read (stream=0xe91431c4800) at istream-seekable.c:265
>         sstream = 0xe91431c4800
>         ret = 16019855444480
>         size = <optimized out>
>         data = <optimized out>
>         pos = <optimized out>
> #10 0x00000e91adc0f0a4 in i_stream_read_memarea (stream=0xe91431c4880) at istream.c:313
>         _stream = 0xe91431c4800
>         old_size = 0
>         ret = <optimized out>
> #11 0x00000e91adc16bbc in i_stream_limit_read (stream=0xe91e9ccca00) at istream-limit.c:49
>         lstream = 0xe91e9ccca00
>         pos = 16017421909770
>         ret = <optimized out>
>         left = <optimized out>
> #12 0x00000e91adc0f0a4 in i_stream_read_memarea (stream=0xe91e9ccca80) at istream.c:313
>         _stream = 0xe91e9ccca00
>         old_size = 0
>         ret = <optimized out>
> #13 0x00000e91adc0f79c in i_stream_read_copy_from_parent (istream=<optimized out>) at istream.c:387
>         stream = 0xe91e9ccc000
>         pos = <optimized out>
>         ret = <optimized out>
> #14 0x00000e918e9729fa in i_stream_mail_read (stream=0xe91e9ccc000) at istream-mail.c:115
>         mstream = 0xe91e9ccc000
>         ret = <optimized out>
>         size = <optimized out>
> #15 0x00000e91adc0f0a4 in i_stream_read_memarea (stream=0xe91e9ccc080) at istream.c:313
>         _stream = 0xe91e9ccc000
>         old_size = 0
>         ret = <optimized out>
> #16 0x00000e91adc104f5 in i_stream_read (stream=0xe91e9ccc080) at istream.c:271
>         _stream = 0xe91e9ccc000
>         ret = <optimized out>
> #17 i_stream_read_data (stream=0xe91e9ccc080, data_r=0x7f7ffffce110, size_r=0x7f7ffffce100, threshold=1)
>     at istream.c:747
>         read_more = false
>         ret = <error reading variable ret (Cannot access memory at address 0x0)>
> #18 0x00000e91adbd6a18 in i_stream_read_bytes (stream=0x0, data_r=<optimized out>,
>     size_r=<optimized out>, wanted=<optimized out>) at ../../src/lib/istream.h:214
> No locals.
> #19 message_parse_header_next (ctx=0xe9183e1b180, hdr_r=0x7f7ffffce1d0) at message-header-parser.c:85
>         skip = <error reading variable skip (Cannot access memory at address 0x0)>
>         line = 0xe9183e1b180
>         colon_pos = 4294967295
>         no_newline = <error reading variable no_newline (Cannot access memory at address 0x0)>
>         crlf_newline = <error reading variable crlf_newline (Cannot access memory at address 0x0)>
>         continued = false
>         size = 0
>         msg = 0xe91adafee50 <uchar_nul> ""
>         startpos = 0
>         continues = <error reading variable continues (Cannot access memory at address 0x0)>
>         i = <optimized out>
>         parse_size = <optimized out>
>         ret = <optimized out>
>         last_crlf = <optimized out>
>         last_no_newline = <optimized out>
> #20 0x00000e91adbceef2 in read_header (mstream=0xe91e9cc6000) at istream-header-filter.c:195
>         highwater_offset = <optimized out>
>         max_buffer_size = 8192
>         hdr = 0x0
>         hdr_ret = <optimized out>
>         ret = <optimized out>
>         ret2 = <optimized out>
> #21 i_stream_header_filter_read (stream=0xe91e9cc6000) at istream-header-filter.c:450
>         mstream = 0xe91e9cc6000
>         v_offset = <optimized out>
>         ret = <optimized out>
> #22 0x00000e91adc0f0a4 in i_stream_read_memarea (stream=0xe91e9cc6080) at istream.c:313
>         _stream = 0xe91e9cc6000
>         old_size = 0
>         ret = <optimized out>
> #23 0x00000e91adc104f5 in i_stream_read (stream=0xe91e9cc6080) at istream.c:271
>         _stream = 0xe91e9cc6000
>         ret = <optimized out>
> #24 i_stream_read_data (stream=0xe91e9cc6080, data_r=0x7f7ffffce2c0, size_r=0x7f7ffffce2c8, threshold=0)
>     at istream.c:747
>         read_more = false
>         ret = <error reading variable ret (Cannot access memory at address 0x0)>
> #25 0x00000e91adbdc07b in i_stream_read_bytes (stream=0xe91e9cc6080, data_r=<optimized out>,
>     size_r=<optimized out>, wanted=<error reading variable: Cannot access memory at address 0x1>)
>     at ../../src/lib/istream.h:214
> No locals.
> #26 message_get_header_size (input=0xe91e9cc6080, hdr=0x7f7ffffce328, has_nuls_r=0x7f7ffffce3b7)
>     at message-size.c:19
>         size = 0
>         msg = 0xe91adafee50 <uchar_nul> ""
>         startpos = <error reading variable startpos (Cannot access memory at address 0x0)>
>         missing_cr_count = <error reading variable missing_cr_count (Cannot access memory at address 0x0)>
>         ret = <optimized out>
>         i = <optimized out>
> #27 0x00000e8f25e767d9 in imap_msgpart_get_partial_header (mail=0xe91e9cc4848,
>     mail_input=<optimized out>, msgpart=0xe91c92a2048, virtual_size_r=<optimized out>,
>     result_r=0x7f7ffffce408, have_crlfs_r=<optimized out>) at imap-msgpart.c:401
>         hdr_size = {
>           physical_size = 0,
>           virtual_size = 0,
>           lines = 0
>         }
>         hdr_fields = 0xe91c92a21f8
>         hdr_count = <optimized out>
>         input = 0xe91e9cc6080
>         has_nuls = false
> #28 imap_msgpart_open_normal (mail=<optimized out>, msgpart=0xe91c92a2048, part=<optimized out>,
>     virtual_size_r=<optimized out>, result_r=0x7f7ffffce408, have_crlfs_r=<optimized out>)
>     at imap-msgpart.c:637
>         hdr_size = {
>           physical_size = 0,
>           virtual_size = 0,
>           lines = 0
>         }
>         body_size = {
>           physical_size = 0,
>           virtual_size = 0,
>           lines = 0
>         }
>         input = <optimized out>
>         unknown_crlfs = <error reading variable unknown_crlfs (Cannot access memory at address 0x0)>
>         part_size = <error reading variable part_size (Cannot access memory at address 0x0)>
> #29 imap_msgpart_open (mail=<optimized out>, msgpart=0xe91c92a2048, result_r=0x7f7ffffce408)
>     at imap-msgpart.c:706
>         part = <optimized out>
>         ret = <optimized out>
>         virtual_size = 1
>         binary = <optimized out>
>         have_crlfs = <optimized out>
> #30 0x00000e8f25e672ff in fetch_body_msgpart (ctx=0xe9159845368, mail=<optimized out>,
>     body=0xe91e9cb4398) at imap-fetch-body.c:184
>         result = {
>           input = 0x0,
>           size = 0,
>           size_field = (unknown: 0),
>           binary_decoded_input_has_nuls = false
>         }
>         str = <optimized out>
> #31 0x00000e8f25e65837 in imap_fetch_more_int (ctx=0xe9159845368, cancel=false) at imap-fetch.c:562
>         _data_stack_cur_id = <optimized out>
>         client = <optimized out>
>         ret = <optimized out>
>         handlers = 0xe91e9cb4020
>         count = 5
> #32 0x00000e8f25e6552c in imap_fetch_more (ctx=0xe9159845368, cmd=0xe9159845048) at imap-fetch.c:617
>         ret = <optimized out>
> #33 0x00000e8f25e55521 in cmd_fetch (cmd=0xe9159845048) at cmd-fetch.c:337
>         qresync_args = {
>           qresync_sample_seqset = 0xe9159845368,
>           qresync_sample_uidset = 0xe9159845020
>         }
>         args = <optimized out>
>         send_vanished = <optimized out>
>         client = 0xe9159845848
>         messageset = <optimized out>
>         search_args = 0x0
>         ret = <optimized out>
>         ctx = 0x0
>         next_arg = <optimized out>
>         list_arg = <optimized out>
> #34 0x00000e8f25e62d12 in command_exec (cmd=0xe9159845048) at imap-commands.c:201
>         hook = <optimized out>
> #35 0x00000e8f25e61576 in client_command_input (cmd=0xe9159845048) at imap-client.c:1204
>         client = 0xe9159845848
>         command = <optimized out>
>         tag = <optimized out>
>         ret = <optimized out>
>         name = <optimized out>
> #36 0x00000e8f25e61682 in client_command_input (cmd=0xe9159845048) at imap-client.c:1269
>         client = 0xe9159845848
>         command = <optimized out>
>         tag = <optimized out>
>         ret = <optimized out>
>         name = <optimized out>
> #37 0x00000e8f25e5ffb4 in client_handle_next_command (client=0xe9159845848, remove_io_r=<optimized out>)
>     at imap-client.c:1313
> No locals.
> #38 client_handle_input (client=0xe9159845848) at imap-client.c:1327
>         _data_stack_cur_id = <optimized out>
>         handled_commands = false
>         ret = <optimized out>
>         remove_io = <optimized out>
> #39 0x00000e8f25e5e755 in client_input (client=0xe9159845848) at imap-client.c:1371
>         output = 0xe92088000a0
>         bytes = 218
>         cmd = <optimized out>
> #40 0x00000e91adc1c851 in io_loop_call_io (io=0xe91eb5d0b00) at ioloop.c:714
>         ioloop = 0xe9162373d00
>         t_id = 0
> #41 0x00000e91adc1f84c in io_loop_handler_run_internal (ioloop=0xe9162373d00) at ioloop-kqueue.c:164
>         tv = {
>           tv_sec = 3,
>           tv_usec = 410626
>         }
>         ts = {
>           tv_sec = 3,
>           tv_nsec = 410626000
>         }
>         ctx = 0xe9171193980
>         msecs = <optimized out>
>         events_count = <optimized out>
>         events = <optimized out>
>         ret = <optimized out>
>         i = <optimized out>
>         io = 0xe91eb5d0b00
> #42 0x00000e91adc1cfd9 in io_loop_handler_run (ioloop=0xe9162373d00) at ioloop.c:766
> No locals.
> #43 0x00000e91adc1cce8 in io_loop_run (ioloop=0xe9162373d00) at ioloop.c:739
> No locals.
> #44 0x00000e91adb77655 in master_service_run (service=0xe9193c39600, callback=0x6)
>     at master-service.c:853
> No locals.
> #45 0x00000e8f25e70dd1 in main (argc=1, argv=<optimized out>) at main.c:532
>         set_roots = {0xe91adc66270 <smtp_submit_setting_parser_info>,
>           0xe8f25e7e310 <imap_setting_parser_info>, 0x0}
>         login_set = {
>           auth_socket_path = 0xe9136774490 "HEADER.FIELDS (DATE FROM SENDER SUBJECT TO CC MESSAGE-ID REFERENCES CONTENT-TYPE CONTENT-DESCRIPTION IN-REPLY-TO REPLY-TO LINES LIST-POST X-LABEL)",
>           postlogin_socket_path = 0x0,
>           postlogin_timeout_secs = 60,
>           callback = 0xe8f25e70fc0 <login_client_connected>,
>           failure_callback = 0xe8f25e712b0 <login_client_failed>,
>           request_auth_token = true
>         }
>         username = <optimized out>
>         storage_service_flags = <optimized out>
>         service_flags = <optimized out>
>         auth_socket_path = <optimized out>
>         c = <optimized out>
>         error = 0x7f7ffffcea18 "]\353\374\377\177\177"
> (gdb)
>
>



More information about the dovecot mailing list