Crash on opening mailbox

Ladislav Laska laska at kam.mff.cuni.cz
Fri Aug 19 19:00:27 UTC 2016


Hi! 

I'm currently experiencing a crash of dovecot 2.2.25 on Gentoo, upon opening 
mailbox. The crash only triggers on opening inbox, other mailboxes seem to work 
fine. It happens every time, and can be reproduced on request. I also briefly 
tried 2.2.19, and it behaves the same.

The bug seems to be triggered by some mail, as I encountered it previously and 
fixed by removing some spam. I guess it might be malformed header of some kind.  
I can open the mailbox locally using mutt, but fail to do so remotely (using 
mutt or K-9 mail on android). Unforunately, I haven't been able to isolate the 
specific mail, as when I create a new mailbox, dovecot refuses to open it:

[CANNOT] Mailbox isn't a valid mbox file (0.000 + 0.000 secs).

I'm not really sure what's going on and will investigate further once I find 
some time to do so.

I also experienced a similar problem on opening a specific mail, but it's much 
harder to reproduce and I currently don't have an example. The crash looks very 
similar, and only happens on first attempt to open a specific mail, it always 
works later on.

I'm attaching a stack trace and dovecot -n. I'm also willing to send the binary 
and core dump, but not publicly, as I'm not eager to share whatever's inside 
with the whole world.

Other than what I mentioned, I'm running pretty standard setup, with postfix on 
Gentoo x86_64, ext4 fs, quota and disk space is plentiful. The delivery agent is 
dovecot itself, in postfix/main.cf I have:

mailbox_command = /usr/libexec/dovecot/deliver

I'm using sieve script to file my mail, but the problem manifested even before 
when I was still using procmail to deliver my mail (I migrated because I had 
doubts about procmail and dovecot lock cooperation)

I'll keep my mailbox corrupted for a few more days, and access the mail only 
locally, hoping to test a potential fix. Let me know if you need any more 
info/experimentation. Also, if you know a good way to find the mail that causes 
the trouble out of the core, let me know, I'd be glad to forward it for testing.

Thanks and I hope we can find (and fix) the problem!

-- 
S pozdravem Ladislav Láska                          <laska at kam.mff.cuni.cz>
Katedra Aplikované Matematiky, MFF UK               tel.: +420 739 464 167
-------------- next part --------------
# 2.2.25 (7be1766): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.4.15 (97b3da0)
# OS: Linux 4.0.4-gentoo x86_64 Gentoo Base System release 2.2 
auth_username_format = %n
hostname = ibex.krakonos.org
login_greeting = Dovecot at krakonos.org ready.
mail_debug = yes
mail_location = mbox:~/.mbox
namespace inbox {
  inbox = yes
  location = 
  mailbox Drafts {
    special_use = \Drafts
  }
  mailbox Junk {
    special_use = \Junk
  }
  mailbox Sent {
    special_use = \Sent
  }
  mailbox "Sent Messages" {
    special_use = \Sent
  }
  mailbox Trash {
    special_use = \Trash
  }
  prefix = 
}
passdb {
  args = *
  driver = pam
}
passdb {
  args = scheme=CRYPT username_format=%u /etc/dovecot/users
  driver = passwd-file
}
plugin {
  sieve = file:~/sieve;active=~/.dovecot.sieve
  sieve_execute_bin_dir = /usr/lib/dovecot/sieve-execute
  sieve_execute_socket_dir = sieve-execute
  sieve_extensions = +vnd.dovecot.filter +editheader
  sieve_filter_bin_dir = /usr/lib/dovecot/sieve-filter
  sieve_filter_socket_dir = sieve-filter
  sieve_pipe_bin_dir = /usr/lib/dovecot/sieve-pipe
  sieve_pipe_socket_dir = sieve-pipe
  sieve_plugins = sieve_extprograms
}
postmaster_address = postmaster at krakonos.org
protocols = imap
service auth {
  unix_listener /var/spool/postfix/private/auth {
    mode = 0666
  }
}
ssl_cert = </etc/ssl/dovecot/server.pem
ssl_key = </etc/ssl/dovecot/server.key
userdb {
  driver = passwd
}
protocol lda {
  mail_plugins = sieve
}
-------------- next part --------------
[New LWP 23407]
Core was generated by `dovecot/imap'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007f328cf22297 in raise () from /lib64/libc.so.6
#0  0x00007f328cf22297 in raise () from /lib64/libc.so.6
No symbol table info available.
#1  0x00007f328cf2362a in abort () from /lib64/libc.so.6
No symbol table info available.
#2  0x00007f328d317916 in default_fatal_finish (type=<optimized out>, status=status at entry=0) at failures.c:201
        backtrace = 0x7a48a0 "/usr/lib64/dovecot/libdovecot.so.0(+0x8d91e) [0x7f328d31791e] -> /usr/lib64/dovecot/libdovecot.so.0(+0x8da0a) [0x7f328d317a0a] -> /usr/lib64/dovecot/libdovecot.so.0(i_fatal+0) [0x7f328d2b5fce] -> /usr"...
#3  0x00007f328d317a0a in i_internal_fatal_handler (ctx=0x7ffc6c9df360, format=<optimized out>, args=<optimized out>) at failures.c:670
        status = 0
#4  0x00007f328d2b5fce in i_panic (format=format at entry=0x7f328d655ce8 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:275
        ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0, timestamp_usecs = 0}
        args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area = 0x7ffc6c9df460, reg_save_area = 0x7ffc6c9df3a0}}
#5  0x00007f328d617e56 in array_idx_i (idx=<optimized out>, array=<optimized out>) at ../../../src/lib/array.h:219
No locals.
#6  index_mail_get_parsed_header (field_idx=<optimized out>, mail=<optimized out>) at index-mail-headers.c:585
        value = 0x7f328d331616 <pool_system_malloc+22> "H\205\300t\025[\303\017\037"
        lines_count = <optimized out>
        value_start = <optimized out>
        value_end = <optimized out>
        i = <optimized out>
        first_line_idx = <optimized out>
#7  index_mail_get_raw_headers (mail=mail at entry=0x7d7e80, field=field at entry=0x7f328d663446 "Message-Id", value_r=value_r at entry=0x7ffc6c9df540) at index-mail-headers.c:656
        _mail = <optimized out>
        headers = {0x7e41f0 "0B~", 0x7f328d88b2d8 <mail_get_first_header at got.plt> ""}
        value = 0x1001 <error: Cannot access memory at address 0x1001>
        headers_ctx = 0x7f328d59a380 <static_system_pool>
        data = <optimized out>
        field_idx = 20
        dest = <optimized out>
        i = <optimized out>
        len = 8212720
        ret = <optimized out>
        __FUNCTION__ = "index_mail_get_raw_headers"
#8  0x00007f328d6182a6 in index_mail_get_first_header (_mail=0x7d7e80, field=0x7f328d663446 "Message-Id", decode_to_utf8=false, value_r=0x7ffc6c9df5e0) at index-mail-headers.c:818
        mail = 0x7d7e80
        list = 0xffffffff009df940
        retry = true
        ret = <optimized out>
#9  0x00007f328d5cb93d in mail_get_first_header (mail=mail at entry=0x7d7e80, field=field at entry=0x7f328d663446 "Message-Id", value_r=value_r at entry=0x7ffc6c9df5e0) at mail.c:187
        _data_stack_cur_id = 5
        p = 0x7d7e80
        ret = <optimized out>
#10 0x00007f328d62be70 in i_stream_mail_get_cached_mail_id (mstream=0x7d5230) at istream-mail.c:50
        orig_lookup_abort = MAIL_LOOKUP_ABORT_NEVER
        value = 0x7d52a0 ";\024"
        ret = 0x7f328d65cc7e ""
        i = <optimized out>
        mail = 0x7d7e80
        headers = {0x7f328d663446 "Message-Id", 0x7f328d6564d5 "Date", 0x7f328d656afc "Subject"}
#11 i_stream_mail_set_size_corrupted (mstream=mstream at entry=0x7d5230, size=size at entry=2887) at istream-mail.c:74
        cur_size = 8066
        str = 0x7f328d663427 "smaller"
        mail_id = <optimized out>
#12 0x00007f328d62c062 in i_stream_mail_read (stream=0x7d5230) at istream-mail.c:109
        mstream = 0x7d5230
        size = 2887
        ret = <optimized out>
#13 0x00007f328d321e03 in i_stream_read (stream=stream at entry=0x7d52a0) at istream.c:174
        _stream = 0x7d5230
        old_size = 1
        ret = <optimized out>
        __FUNCTION__ = "i_stream_read"
#14 0x00007f328d32283d in i_stream_read_data (stream=0x7d52a0, data_r=data_r at entry=0x7ffc6c9df6d8, size_r=size_r at entry=0x7ffc6c9df6e0, threshold=threshold at entry=1) at istream.c:563
        ret = <optimized out>
        read_more = false
        __FUNCTION__ = "i_stream_read_data"
#15 0x00007f328d303042 in message_parse_header_next (ctx=0x7e2ee0, hdr_r=hdr_r at entry=0x7ffc6c9df780) at message-header-parser.c:84
        line = 0x7e2ee0
        msg = 0x7dd2f2 "XQgc2UgbWFwb3ZhdCBha3R1YWxuaSBwb2tyeXRpIHNpZ25hbHUgbmVtYSBzbXlzbCwg\namVkbmFrIHNlIHN0YWxlIG1lbmkgYQpwb3RyZWJuYSBkYXRhIG8gbmFzdGF2ZW5pIHZ5a29udSBh\nIHNtZXJvdmFuaSBhbnRlbiB6bmEgamVub20gb3BlcmF0b3IuCgpDbyB"...
        i = <optimized out>
        size = 1
        startpos = 0
        colon_pos = 4294967295
        parse_size = <optimized out>
        skip = 0
        ret = <optimized out>
        continued = false
        continues = false
        last_no_newline = <optimized out>
        last_crlf = <optimized out>
        no_newline = false
        crlf_newline = false
        __FUNCTION__ = "message_parse_header_next"
#16 0x00007f328d2fd6c1 in read_header (mstream=0x7df5a0) at istream-header-filter.c:194
        max_buffer_size = <optimized out>
        ret = <optimized out>
        hdr = 0x0
        highwater_offset = <optimized out>
        ret2 = <optimized out>
        hdr_ret = <optimized out>
#17 i_stream_header_filter_read (stream=0x7df5a0) at istream-header-filter.c:425
        mstream = 0x7df5a0
#18 0x00007f328d321e03 in i_stream_read (stream=stream at entry=0x7df610) at istream.c:174
        _stream = 0x7df5a0
        old_size = 43
        ret = <optimized out>
        __FUNCTION__ = "i_stream_read"
#19 0x00007f328d32283d in i_stream_read_data (stream=0x7df610, data_r=data_r at entry=0x7ffc6c9df858, size_r=size_r at entry=0x7ffc6c9df860, threshold=threshold at entry=43) at istream.c:563
        ret = <optimized out>
        read_more = false
        __FUNCTION__ = "i_stream_read_data"
#20 0x00007f328d303042 in message_parse_header_next (ctx=0x7e1a20, hdr_r=hdr_r at entry=0x7ffc6c9df900) at message-header-parser.c:84
        line = 0x7e1a20
        msg = 0x7df974 "Content-Type: text/plain; charset=\"utf-8\"\r\netmap.org>\r\n)\r\nt>\r\n95 at amd>\r\n\r\n"
        i = <optimized out>
        size = 43
        startpos = 42
        colon_pos = 12
        parse_size = <optimized out>
        skip = 0
        ret = <optimized out>
        continued = false
        continues = false
        last_no_newline = <optimized out>
        last_crlf = <optimized out>
        no_newline = false
        crlf_newline = false
        __FUNCTION__ = "message_parse_header_next"
#21 0x00007f328d2fd6c1 in read_header (mstream=0x7e07e0) at istream-header-filter.c:194
        max_buffer_size = <optimized out>
        ret = <optimized out>
        hdr = 0x0
        highwater_offset = <optimized out>
        ret2 = <optimized out>
        hdr_ret = <optimized out>
#22 i_stream_header_filter_read (stream=0x7e07e0) at istream-header-filter.c:425
        mstream = 0x7e07e0
#23 0x00007f328d321e03 in i_stream_read (stream=stream at entry=0x7e0850) at istream.c:174
        _stream = 0x7e07e0
        old_size = 2
        ret = <optimized out>
        __FUNCTION__ = "i_stream_read"
#24 0x00007f328d32283d in i_stream_read_data (stream=stream at entry=0x7e0850, data_r=data_r at entry=0x7ffc6c9df9d8, size_r=size_r at entry=0x7ffc6c9df9e0, threshold=threshold at entry=2) at istream.c:563
        ret = <optimized out>
        read_more = false
        __FUNCTION__ = "i_stream_read_data"
#25 0x00007f328d306d64 in message_get_header_size (input=0x7e0850, hdr=hdr at entry=0x7ffc6c9dfad0, has_nuls_r=has_nuls_r at entry=0x7ffc6c9dfa4f) at message-size.c:19
        msg = 0x7e0bb4 "\r\n>\r\n"
        i = <optimized out>
        size = 2
        startpos = 2
        missing_cr_count = 0
        ret = <optimized out>
        __FUNCTION__ = "message_get_header_size"
#26 0x00007f328d654ff7 in imap_msgpart_get_partial_header (mail=<optimized out>, msgpart=<optimized out>, msgpart=<optimized out>, result_r=0x7ffc6c9dfb40, have_crlfs_r=<synthetic pointer>, virtual_size_r=0x7ffc6c9dfa58, mail_input=0x7df610) at imap-msgpart.c:395
        hdr_fields = 0x7cdc38
        hdr_size = {physical_size = 1069, virtual_size = 0, lines = 19}
        hdr_count = <optimized out>
        input = 0x7e0850
        has_nuls = false
#27 imap_msgpart_open_normal (result_r=0x7ffc6c9dfb40, have_crlfs_r=<synthetic pointer>, virtual_size_r=0x7ffc6c9dfa58, part=<optimized out>, msgpart=0x7cdad0, mail=0x7d7e80) at imap-msgpart.c:630
        hdr_size = {physical_size = 0, virtual_size = 0, lines = 0}
        part_size = {physical_size = 0, virtual_size = 0, lines = 0}
        unknown_crlfs = <optimized out>
        body_size = {physical_size = 0, virtual_size = 0, lines = 0}
        input = 0x7df610
#28 imap_msgpart_open (mail=0x7d7e80, msgpart=0x7cdad0, result_r=result_r at entry=0x7ffc6c9dfb40) at imap-msgpart.c:699
        part = 0x0
        virtual_size = 6789327327946376192
        include_hdr = <optimized out>
        binary = false
        use_partial_cache = <optimized out>
        have_crlfs = <optimized out>
#29 0x000000000041d4ae in fetch_body_msgpart (ctx=0x7c6708, mail=<optimized out>, body=0x7d0eb0) at imap-fetch-body.c:185
        result = {input = 0x0, size = 0, size_field = (unknown: 0), binary_decoded_input_has_nuls = false}
        str = 0x7c67a0
#30 0x000000000041b9fc in imap_fetch_more_int (ctx=ctx at entry=0x7c6708, cancel=false) at imap-fetch.c:505
        h = <optimized out>
        _data_stack_cur_id = 4
        state = 0x7c6758
        client = 0x7c5680
        count = <optimized out>
        ret = <optimized out>
        __FUNCTION__ = "imap_fetch_more_int"
#31 0x000000000041ca0a in imap_fetch_more (ctx=0x7c6708, cmd=cmd at entry=0x7c6260) at imap-fetch.c:557
        ret = <optimized out>
        __FUNCTION__ = "imap_fetch_more"
#32 0x000000000040f57c in cmd_fetch (cmd=0x7c6260) at cmd-fetch.c:297
        client = 0x7c5680
        ctx = 0x7c6708
        args = 0x7b08f8
        next_arg = <optimized out>
        list_arg = 0x1
        search_args = 0x0
        qresync_args = {qresync_sample_seqset = 0x7a45c0, qresync_sample_uidset = 0xa}
        messageset = 0x7ce2d0 "147131,147130,147129,147128,147127,147126,147125,147124,147123,147122,147121,147120,147119,147118,147117,147116,147115,147114,147112,147111,147110,147109,147108,147107,147106,147105,147104,147103,1471"...
        send_vanished = <optimized out>
        ret = <optimized out>
#33 0x000000000041a29c in command_exec (cmd=cmd at entry=0x7c6260) at imap-commands.c:180
        hook = 0x7ad0f0
        finished = <optimized out>
        cmd_start_timeval = {tv_sec = 1471632720, tv_usec = 52660}
        cmd_start_bytes_in = 68
        cmd_start_bytes_out = 1509
        __FUNCTION__ = "command_exec"
#34 0x0000000000418772 in client_command_input (cmd=cmd at entry=0x7c6260) at imap-client.c:969
        client = 0x7c5680
        command = <optimized out>
        __FUNCTION__ = "client_command_input"
#35 0x0000000000418800 in client_command_input (cmd=0x7c6260) at imap-client.c:1029
        client = 0x7c5680
        command = <optimized out>
        __FUNCTION__ = "client_command_input"
#36 0x0000000000418b95 in client_handle_next_command (remove_io_r=<synthetic pointer>, client=0x7c5680) at imap-client.c:1069
No locals.
#37 client_handle_input (client=0x7c5680) at imap-client.c:1081
        _data_stack_cur_id = 3
        remove_io = false
        handled_commands = false
        client = 0x7c5680
#38 0x0000000000419042 in client_input (client=0x7c5680) at imap-client.c:1128
        cmd = 0xcd8d
        output = 0x7c60a0
        bytes = 875
        __FUNCTION__ = "client_input"
#39 0x00007f328d32b7dc in io_loop_call_io (io=0x7c6170) at ioloop.c:564
        ioloop = 0x7ac730
        t_id = 2
        __FUNCTION__ = "io_loop_call_io"
#40 0x00007f328d32cc41 in io_loop_handler_run_internal (ioloop=ioloop at entry=0x7ac730) at ioloop-epoll.c:220
        ctx = 0x7ae240
        io = <optimized out>
        tv = {tv_sec = 1799, tv_usec = 999818}
        events_count = <optimized out>
        msecs = <optimized out>
        ret = 1
        i = 0
        j = <optimized out>
        call = <optimized out>
        __FUNCTION__ = "io_loop_handler_run_internal"
#41 0x00007f328d32b865 in io_loop_handler_run (ioloop=ioloop at entry=0x7ac730) at ioloop.c:612
No locals.
#42 0x00007f328d32ba08 in io_loop_run (ioloop=0x7ac730) at ioloop.c:588
        __FUNCTION__ = "io_loop_run"
#43 0x00007f328d2bc3e3 in master_service_run (service=0x7ac5d0, callback=callback at entry=0x424f30 <client_connected>) at master-service.c:640
No locals.
#44 0x000000000040c912 in main (argc=1, argv=0x7ac390) at main.c:460
        set_roots = {0x42dc40 <imap_setting_parser_info>, 0x6371c0 <lda_setting_parser_info>, 0x0}
        login_set = {auth_socket_path = 0x7a4048 "\001", postlogin_socket_path = 0x0, postlogin_timeout_secs = 60, callback = 0x425700 <login_client_connected>, failure_callback = 0x425040 <login_client_failed>, request_auth_token = 1}
        service_flags = <optimized out>
        storage_service_flags = <optimized out>
        username = 0x0
        auth_socket_path = 0x42ebee "auth-master"
        c = <optimized out>


More information about the dovecot mailing list