On 2021-01-24, Stuart Henderson <s...@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)
>
>
